
# Create a temporary directory to hold notebook output, and change the working directory to that directory.
import shutil
import os
from tempfile import TemporaryDirectory

use_tempdir = True
if use_tempdir:
    # Create temporary directory
    data_dir = TemporaryDirectory()
    # Save original directory
    orig_dir = os.getcwd()
    # Move to new directory
    os.chdir(data_dir.name)

# For info, print out where the script is running
print("Running in {}".format(os.getcwd()))

Running in /internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh


import os
if 'CRDS_CACHE_TYPE' in os.environ:
    if os.environ['CRDS_CACHE_TYPE'] == 'local':
        os.environ['CRDS_PATH'] = os.path.join(os.environ['HOME'], 'crds', 'cache')
    elif os.path.isdir(os.environ['CRDS_CACHE_TYPE']):
        os.environ['CRDS_PATH'] = os.environ['CRDS_CACHE_TYPE']
print('CRDS cache location: {}'.format(os.environ['CRDS_PATH']))

CRDS cache location: /grp/crds/cache


import warnings
import psutil
from astropy.io import fits

# Only print a DeprecationWarning the first time it shows up, not every time.
with warnings.catch_warnings():
    warnings.simplefilter("once", category=DeprecationWarning)
    import jwst
    from jwst.pipeline.calwebb_detector1 import Detector1Pipeline
    from jwst.assign_wcs.assign_wcs_step import AssignWcsStep
    from jwst.msaflagopen.msaflagopen_step import MSAFlagOpenStep
    from jwst.extract_2d.extract_2d_step import Extract2dStep
    from jwst.srctype.srctype_step import SourceTypeStep
    from jwst.wavecorr.wavecorr_step import WavecorrStep
    from jwst.flatfield.flat_field_step import FlatFieldStep
    from jwst.pathloss.pathloss_step import PathLossStep
    from jwst.barshadow import BarShadowStep
    from jwst import datamodels

# The latest version of NPTT is installed in the requirements text file at:
# /jwst_validation_notebooks/environment.yml

# import NPTT
import nirspec_pipe_testing_tool as nptt

# To get data from Artifactory
from ci_watson.artifactory_helpers import get_bigdata


# Print the versions used for the pipeline and NPTT

pipeline_version = jwst.__version__
nptt_version = nptt.__version__

print("Using jwst pipeline version: ", pipeline_version)
print("Using NPTT version: ", nptt_version)

Using jwst pipeline version:  1.8.2
Using NPTT version:  2.0.1


testing_data = {              
                'mos_prism_clear':{
                                  'uncal_file_nrs1': 'mos_prism_nrs1_uncal.fits',
                                  'uncal_file_nrs2': 'mos_prism_nrs2_uncal.fits',
                                  'msa_shutter_config': 'V0030006000104_msa.fits' },
                
                'mos_g140m_f100lp':{
                                  'uncal_file_nrs1': 'mos_g140m_line1_NRS1_uncal.fits',
                                  'uncal_file_nrs2': 'mos_g140m_line1_NRS2_uncal.fits',  
                                  'msa_shutter_config': 'V8460001000101_msa.fits' }
                }


# define function to pull data from Artifactory
def get_artifactory_file(data_set_dict, detector):
    """This function creates a list with all the files needed per detector to run the test.
    Args:
        data_set_dict: dictionary, contains inputs for a specific mode and configuration
        detector: string, either nrs1 or nrs2
    Returns:
        data: list, contains all files needed to run test
    """
    files2obtain = ['uncal_file_nrs1', 'msa_shutter_config']
    data = []
    for file in files2obtain:
        data_file = None
        try: 
            if '_nrs' in file and '2' in detector:
                file = file.replace('_nrs1', '_nrs2')

            data_file = get_bigdata('jwst_validation_notebooks',
                                         'validation_data',
                                         'nirspec_data', 
                                         data_set_dict[file])
        except TypeError:
            data.append(None)
            continue

        data.append(data_file)

    return data


# Set common NPTT switches for this test

# accepted threshold difference with respect to benchmark files
barshadow_threshold_diff = 0.0025

# other variables
mode_used = 'MOS'
write_barshadow_files = False
show_final_fig = True
save_final_fig = False
show_intermediary_figs = False
save_intermediary_figs = False

# Get the data
results_dict = {}
detectors = ['nrs1', 'nrs2']
for mode_config, data_set_dict in testing_data.items():
    for det in detectors:
        print('Testing files for detector: ', det)
        data = get_artifactory_file(data_set_dict, det)
        uncal_file, msa_shutter_config = data
        print('Working with uncal_file: ', uncal_file)
        uncal_basename = os.path.basename(uncal_file)
        
        # Run the stage 1 pipeline 
        rate_object = Detector1Pipeline.call(uncal_file)
        # Make sure the MSA shutter configuration file is set up correctly
        if msa_shutter_config is not None:
            msa_metadata = rate_object.meta.instrument.msa_metadata_file
            if msa_metadata is None or msa_metadata == 'N/A':
                rate_object.meta.instrument.msa_metadata_file = msa_shutter_config

        # Run the stage 2 pipeline steps
        try:
            pipe_object = AssignWcsStep.call(rate_object)
            skip_file = False
        except:
            print("No open slits fall on detector ", det)
            print("Skipping test for this file. \n")
            skip_file = True
            
        if not skip_file: 
            pipe_object = MSAFlagOpenStep.call(pipe_object)
            pipe_object = Extract2dStep.call(pipe_object)
            pipe_object = SourceTypeStep.call(pipe_object)
            pipe_object = WavecorrStep.call(pipe_object)
            pipe_object = FlatFieldStep.call(pipe_object, save_interpolated_flat=False)
            pathloss_object = PathLossStep.call(pipe_object)
            barshadow_object = BarShadowStep.call(pathloss_object)

            # Run the validation test
            %matplotlib inline

            result, _, _ = nptt.calwebb_spec2_pytests.auxiliary_code.barshadow_testing.run_barshadow_tests(
                                                                pathloss_object, 
                                                                barshadow_object,
                                                                barshadow_threshold_diff=barshadow_threshold_diff,
                                                                save_final_figs=save_final_fig,
                                                                show_final_figs=show_final_fig,
                                                                save_intermediary_figs=save_intermediary_figs,
                                                                show_intermediary_figs=show_intermediary_figs,
                                                                write_barshadow_files=write_barshadow_files)

        else:
            result = 'skipped'

        # Did the test passed 
        print("Did barshadow validation test passed? ", result, "\n\n")
        rd = {uncal_basename: result}
        results_dict.update(rd)
        
        # close all open files
        psutil.Process().open_files()
        closing_files = []
        for fd in psutil.Process().open_files():
            if data_dir.name in fd.path:
                closing_files.append(fd)
        for fd in closing_files:
            try:
                print('Closing file: ', fd)
                open(fd.fd).close()
            except:
                print('File already closed: ', fd)

Testing files for detector:  nrs1
Working with uncal_file:  /internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh/mos_prism_nrs1_uncal.fits

2022-12-02 15:52:16,124 - stpipe - INFO - PARS-DETECTOR1PIPELINE parameters found: /grp/crds/cache/references/jwst/jwst_nirspec_pars-detector1pipeline_0004.asdf
2022-12-02 15:52:16,159 - stpipe.Detector1Pipeline - INFO - Detector1Pipeline instance created.
2022-12-02 15:52:16,161 - stpipe.Detector1Pipeline.group_scale - INFO - GroupScaleStep instance created.
2022-12-02 15:52:16,162 - stpipe.Detector1Pipeline.dq_init - INFO - DQInitStep instance created.
2022-12-02 15:52:16,163 - stpipe.Detector1Pipeline.saturation - INFO - SaturationStep instance created.
2022-12-02 15:52:16,164 - stpipe.Detector1Pipeline.ipc - INFO - IPCStep instance created.
2022-12-02 15:52:16,165 - stpipe.Detector1Pipeline.superbias - INFO - SuperBiasStep instance created.
2022-12-02 15:52:16,166 - stpipe.Detector1Pipeline.refpix - INFO - RefPixStep instance created.
2022-12-02 15:52:16,168 - stpipe.Detector1Pipeline.rscd - INFO - RscdStep instance created.
2022-12-02 15:52:16,169 - stpipe.Detector1Pipeline.firstframe - INFO - FirstFrameStep instance created.
2022-12-02 15:52:16,171 - stpipe.Detector1Pipeline.lastframe - INFO - LastFrameStep instance created.
2022-12-02 15:52:16,172 - stpipe.Detector1Pipeline.linearity - INFO - LinearityStep instance created.
2022-12-02 15:52:16,173 - stpipe.Detector1Pipeline.dark_current - INFO - DarkCurrentStep instance created.
2022-12-02 15:52:16,174 - stpipe.Detector1Pipeline.reset - INFO - ResetStep instance created.
2022-12-02 15:52:16,175 - stpipe.Detector1Pipeline.persistence - INFO - PersistenceStep instance created.
2022-12-02 15:52:16,177 - stpipe.Detector1Pipeline.jump - INFO - JumpStep instance created.
2022-12-02 15:52:16,178 - stpipe.Detector1Pipeline.ramp_fit - INFO - RampFitStep instance created.
2022-12-02 15:52:16,179 - stpipe.Detector1Pipeline.gain_scale - INFO - GainScaleStep instance created.
2022-12-02 15:52:16,372 - stpipe.Detector1Pipeline - INFO - Step Detector1Pipeline running with args ('/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh/mos_prism_nrs1_uncal.fits',).
2022-12-02 15:52:16,382 - stpipe.Detector1Pipeline - INFO - Step Detector1Pipeline parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'save_calibrated_ramp': False, 'steps': {'group_scale': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'dq_init': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'saturation': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'n_pix_grow_sat': 1}, 'ipc': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': True, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'superbias': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'refpix': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'odd_even_columns': True, 'use_side_ref_pixels': True, 'side_smoothing_length': 11, 'side_gain': 1.0, 'odd_even_rows': True}, 'rscd': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'type': 'baseline'}, 'firstframe': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'lastframe': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'linearity': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'dark_current': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'dark_output': None}, 'reset': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'persistence': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'input_trapsfilled': '', 'flag_pers_cutoff': 40.0, 'save_persistence': False, 'save_trapsfilled': True}, 'jump': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'rejection_threshold': 4.0, 'three_group_rejection_threshold': 6.0, 'four_group_rejection_threshold': 5.0, 'maximum_cores': 'none', 'flag_4_neighbors': True, 'max_jump_to_flag_neighbors': 1000.0, 'min_jump_to_flag_neighbors': 10.0, 'after_jump_flag_dn1': 0.0, 'after_jump_flag_time1': 0.0, 'after_jump_flag_dn2': 0.0, 'after_jump_flag_time2': 0.0, 'min_sat_area': 1.0, 'min_jump_area': 5.0, 'expand_factor': 2.0, 'use_ellipses': False, 'sat_required_snowball': True, 'expand_large_events': False}, 'ramp_fit': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'int_name': '', 'save_opt': False, 'opt_name': '', 'suppress_one_group': True, 'maximum_cores': 'none'}, 'gain_scale': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}}}
2022-12-02 15:52:16,575 - stpipe.Detector1Pipeline - INFO - Prefetching reference files for dataset: 'mos_prism_nrs1_uncal.fits' reftypes = ['dark', 'gain', 'linearity', 'mask', 'persat', 'readnoise', 'refpix', 'reset', 'rscd', 'saturation', 'superbias', 'trapdensity', 'trappars']
2022-12-02 15:52:16,585 - stpipe.Detector1Pipeline - INFO - Prefetch for DARK reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_dark_0086.fits'.
2022-12-02 15:52:16,587 - stpipe.Detector1Pipeline - INFO - Prefetch for GAIN reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_gain_0019.fits'.
2022-12-02 15:52:16,588 - stpipe.Detector1Pipeline - INFO - Prefetch for LINEARITY reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_linearity_0018.fits'.
2022-12-02 15:52:16,590 - stpipe.Detector1Pipeline - INFO - Prefetch for MASK reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_mask_0010.fits'.
2022-12-02 15:52:16,592 - stpipe.Detector1Pipeline - INFO - Prefetch for PERSAT reference file is 'N/A'.
2022-12-02 15:52:16,592 - stpipe.Detector1Pipeline - INFO - Prefetch for READNOISE reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_readnoise_0018.fits'.
2022-12-02 15:52:16,594 - stpipe.Detector1Pipeline - INFO - Prefetch for REFPIX reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_refpix_0022.fits'.
2022-12-02 15:52:16,595 - stpipe.Detector1Pipeline - INFO - Prefetch for RESET reference file is 'N/A'.
2022-12-02 15:52:16,596 - stpipe.Detector1Pipeline - INFO - Prefetch for RSCD reference file is 'N/A'.
2022-12-02 15:52:16,596 - stpipe.Detector1Pipeline - INFO - Prefetch for SATURATION reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_saturation_0020.fits'.
2022-12-02 15:52:16,598 - stpipe.Detector1Pipeline - INFO - Prefetch for SUPERBIAS reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_superbias_0113.fits'.
2022-12-02 15:52:16,599 - stpipe.Detector1Pipeline - INFO - Prefetch for TRAPDENSITY reference file is 'N/A'.
2022-12-02 15:52:16,600 - stpipe.Detector1Pipeline - INFO - Prefetch for TRAPPARS reference file is 'N/A'.
2022-12-02 15:52:16,600 - stpipe.Detector1Pipeline - INFO - Starting calwebb_detector1 ...
2022-12-02 15:52:17,083 - stpipe.Detector1Pipeline.group_scale - INFO - Step group_scale running with args (<RampModel(1, 4, 3200, 2048) from mos_prism_nrs1_uncal.fits>,).
2022-12-02 15:52:17,085 - stpipe.Detector1Pipeline.group_scale - INFO - Step group_scale parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh'}
2022-12-02 15:52:17,241 - stpipe.Detector1Pipeline.group_scale - INFO - NFRAMES and FRMDIVSR are equal; correction not needed
2022-12-02 15:52:17,242 - stpipe.Detector1Pipeline.group_scale - INFO - Step will be skipped
2022-12-02 15:52:17,245 - stpipe.Detector1Pipeline.group_scale - INFO - Step group_scale done
2022-12-02 15:52:17,432 - stpipe.Detector1Pipeline.dq_init - INFO - Step dq_init running with args (<RampModel(1, 4, 3200, 2048) from mos_prism_nrs1_uncal.fits>,).
2022-12-02 15:52:17,433 - stpipe.Detector1Pipeline.dq_init - INFO - Step dq_init parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh'}
2022-12-02 15:52:17,458 - stpipe.Detector1Pipeline.dq_init - INFO - Using MASK reference file /grp/crds/cache/references/jwst/jwst_nirspec_mask_0010.fits
2022-12-02 15:52:18,333 - stpipe.Detector1Pipeline.dq_init - INFO - Step dq_init done
2022-12-02 15:52:18,514 - stpipe.Detector1Pipeline.saturation - INFO - Step saturation running with args (<RampModel(1, 4, 3200, 2048) from mos_prism_nrs1_uncal.fits>,).
2022-12-02 15:52:18,516 - stpipe.Detector1Pipeline.saturation - INFO - Step saturation parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh', 'n_pix_grow_sat': 1}
2022-12-02 15:52:18,541 - stpipe.Detector1Pipeline.saturation - INFO - Using SATURATION reference file /grp/crds/cache/references/jwst/jwst_nirspec_saturation_0020.fits
2022-12-02 15:52:20,359 - stpipe.Detector1Pipeline.saturation - INFO - Detected 49730 saturated pixels
2022-12-02 15:52:20,401 - stpipe.Detector1Pipeline.saturation - INFO - Detected 0 A/D floor pixels
2022-12-02 15:52:20,434 - stpipe.Detector1Pipeline.saturation - INFO - Step saturation done
2022-12-02 15:52:20,643 - stpipe.Detector1Pipeline.ipc - INFO - Step ipc running with args (<RampModel(1, 4, 3200, 2048) from mos_prism_nrs1_uncal.fits>,).
2022-12-02 15:52:20,645 - stpipe.Detector1Pipeline.ipc - INFO - Step ipc parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': True, 'suffix': None, 'search_output_file': True, 'input_dir': '/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh'}
2022-12-02 15:52:20,646 - stpipe.Detector1Pipeline.ipc - INFO - Step skipped.
2022-12-02 15:52:20,650 - stpipe.Detector1Pipeline.ipc - INFO - Step ipc done
2022-12-02 15:52:20,843 - stpipe.Detector1Pipeline.superbias - INFO - Step superbias running with args (<RampModel(1, 4, 3200, 2048) from mos_prism_nrs1_uncal.fits>,).
2022-12-02 15:52:20,845 - stpipe.Detector1Pipeline.superbias - INFO - Step superbias parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh'}
2022-12-02 15:52:20,871 - stpipe.Detector1Pipeline.superbias - INFO - Using SUPERBIAS reference file /grp/crds/cache/references/jwst/jwst_nirspec_superbias_0113.fits
/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.9/site-packages/stdatamodels/validate.py:38: ValidationWarning: While validating meta.exposure.readpatt the following error occurred:
'ALLIRS2' is not one of ['ACQ1', 'ACQ2', 'BRIGHT1', 'BRIGHT2', 'DEEP2', 'DEEP8', 'FAST', 'FASTGRPAVG', 'FASTGRPAVG8', 'FASTGRPAVG16', 'FASTGRPAVG32', 'FASTGRPAVG64', 'FASTR1', 'FASTR100', 'FGS', 'FGS60', 'FGS8370', 'FGS840', 'FGSRAPID', 'FINEGUIDE', 'ID', 'MEDIUM2', 'MEDIUM8', 'NIS', 'NISRAPID', 'NRS', 'NRSIRS2', 'NRSN16R4', 'NRSN32R8', 'NRSN8R2', 'NRSRAPID', 'NRSIRS2RAPID', 'NRSRAPIDD1', 'NRSRAPIDD2', 'NRSRAPIDD6', 'NRSSLOW', 'RAPID', 'SHALLOW2', 'SHALLOW4', 'SLOW', 'SLOWR1', 'TRACK', 'ANY', 'N/A']

Failed validating 'enum' in schema:
    OrderedDict([('title', 'Readout pattern'),
                 ('type', 'string'),
                 ('enum',
                  ['ACQ1',
                   'ACQ2',
                   'BRIGHT1',
                   'BRIGHT2',
                   'DEEP2',
                   'DEEP8',
                   'FAST',
                   'FASTGRPAVG',
                   'FASTGRPAVG8',
                   'FASTGRPAVG16',
                   'FASTGRPAVG32',
                   'FASTGRPAVG64',
                   'FASTR1',
                   'FASTR100',
                   'FGS',
                   'FGS60',
                   'FGS8370',
                   'FGS840',
                   'FGSRAPID',
                   'FINEGUIDE',
                   'ID',
                   'MEDIUM2',
                   'MEDIUM8',
                   'NIS',
                   'NISRAPID',
                   'NRS',
                   'NRSIRS2',
                   'NRSN16R4',
                   'NRSN32R8',
                   'NRSN8R2',
                   'NRSRAPID',
                   'NRSIRS2RAPID',
                   'NRSRAPIDD1',
                   'NRSRAPIDD2',
                   'NRSRAPIDD6',
                   'NRSSLOW',
                   'RAPID',
                   'SHALLOW2',
                   'SHALLOW4',
                   'SLOW',
                   'SLOWR1',
                   'TRACK',
                   'ANY',
                   'N/A']),
                 ('fits_ke ...
  warnings.warn(errmsg, ValidationWarning)
2022-12-02 15:52:23,690 - stpipe.Detector1Pipeline.superbias - INFO - Step superbias done
2022-12-02 15:52:23,870 - stpipe.Detector1Pipeline.refpix - INFO - Step refpix running with args (<RampModel(1, 4, 3200, 2048) from mos_prism_nrs1_uncal.fits>,).
2022-12-02 15:52:23,872 - stpipe.Detector1Pipeline.refpix - INFO - Step refpix parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh', 'odd_even_columns': True, 'use_side_ref_pixels': True, 'side_smoothing_length': 11, 'side_gain': 1.0, 'odd_even_rows': True}
2022-12-02 15:52:23,898 - stpipe.Detector1Pipeline.refpix - INFO - Using refpix reference file: /grp/crds/cache/references/jwst/jwst_nirspec_refpix_0022.fits
2022-12-02 15:52:26,656 - stpipe.Detector1Pipeline.refpix - INFO - Working on integration 1
2022-12-02 15:52:40,635 - stpipe.Detector1Pipeline.refpix - INFO - Step refpix done
2022-12-02 15:52:40,930 - stpipe.Detector1Pipeline.linearity - INFO - Step linearity running with args (<RampModel(1, 4, 3200, 2048) from mos_prism_nrs1_uncal.fits>,).
2022-12-02 15:52:40,932 - stpipe.Detector1Pipeline.linearity - INFO - Step linearity parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh'}
2022-12-02 15:52:40,957 - stpipe.Detector1Pipeline.linearity - INFO - Using Linearity reference file /grp/crds/cache/references/jwst/jwst_nirspec_linearity_0018.fits
2022-12-02 15:52:43,984 - stpipe.Detector1Pipeline.linearity - INFO - Step linearity done
2022-12-02 15:52:44,212 - stpipe.Detector1Pipeline.dark_current - INFO - Step dark_current running with args (<RampModel(1, 4, 3200, 2048) from mos_prism_nrs1_uncal.fits>,).
2022-12-02 15:52:44,214 - stpipe.Detector1Pipeline.dark_current - INFO - Step dark_current parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh', 'dark_output': None}
2022-12-02 15:52:44,311 - stpipe.Detector1Pipeline.dark_current - INFO - Using DARK reference file /grp/crds/cache/references/jwst/jwst_nirspec_dark_0086.fits
2022-12-02 15:53:15,320 - stpipe.Detector1Pipeline.dark_current - INFO - Science data nints=1, ngroups=4, nframes=1, groupgap=0
2022-12-02 15:53:15,321 - stpipe.Detector1Pipeline.dark_current - INFO - Dark data nints=1, ngroups=65, nframes=1, groupgap=0
2022-12-02 15:53:15,965 - stpipe.Detector1Pipeline.dark_current - INFO - Step dark_current done
2022-12-02 15:53:16,134 - stpipe.Detector1Pipeline.jump - INFO - Step jump running with args (<RampModel(1, 4, 3200, 2048) from mos_prism_nrs1_uncal.fits>,).
2022-12-02 15:53:16,136 - stpipe.Detector1Pipeline.jump - INFO - Step jump parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh', 'rejection_threshold': 4.0, 'three_group_rejection_threshold': 6.0, 'four_group_rejection_threshold': 5.0, 'maximum_cores': 'none', 'flag_4_neighbors': True, 'max_jump_to_flag_neighbors': 1000.0, 'min_jump_to_flag_neighbors': 10.0, 'after_jump_flag_dn1': 0.0, 'after_jump_flag_time1': 0.0, 'after_jump_flag_dn2': 0.0, 'after_jump_flag_time2': 0.0, 'min_sat_area': 1.0, 'min_jump_area': 5.0, 'expand_factor': 2.0, 'use_ellipses': False, 'sat_required_snowball': True, 'expand_large_events': False}
2022-12-02 15:53:16,175 - stpipe.Detector1Pipeline.jump - INFO - CR rejection threshold = 4 sigma
2022-12-02 15:53:16,227 - stpipe.Detector1Pipeline.jump - INFO - Using GAIN reference file: /grp/crds/cache/references/jwst/jwst_nirspec_gain_0019.fits
2022-12-02 15:53:16,516 - stpipe.Detector1Pipeline.jump - INFO - Using READNOISE reference file: /grp/crds/cache/references/jwst/jwst_nirspec_readnoise_0018.fits
2022-12-02 15:53:16,977 - stpipe.Detector1Pipeline.jump - INFO - Executing two-point difference method
2022-12-02 15:53:17,019 - stpipe.Detector1Pipeline.jump - INFO - Working on integration 1:
/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.9/site-packages/stcal/jump/twopoint_difference.py:154: RuntimeWarning: All-NaN slice encountered
  max_ratio = np.nanmax(ratio, axis=0)
2022-12-02 15:53:18,454 - stpipe.Detector1Pipeline.jump - INFO - From highest outlier, two-point found 0 pixels with at least one CR from five or more groups.
2022-12-02 15:53:19,086 - stpipe.Detector1Pipeline.jump - INFO - Total elapsed time = 2.10857 sec
/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.9/site-packages/stcal/jump/jump.py:302: RuntimeWarning: invalid value encountered in divide
  data /= gain_2d
/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.9/site-packages/stcal/jump/jump.py:303: RuntimeWarning: invalid value encountered in divide
  err /= gain_2d
/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.9/site-packages/stcal/jump/jump.py:304: RuntimeWarning: invalid value encountered in divide
  readnoise_2d /= gain_2d
2022-12-02 15:53:19,137 - stpipe.Detector1Pipeline.jump - INFO - The execution time in seconds: 2.962133
2022-12-02 15:53:19,143 - stpipe.Detector1Pipeline.jump - INFO - Step jump done
2022-12-02 15:53:19,282 - stpipe.Detector1Pipeline.ramp_fit - INFO - Step ramp_fit running with args (<RampModel(1, 4, 3200, 2048) from mos_prism_nrs1_uncal.fits>,).
2022-12-02 15:53:19,285 - stpipe.Detector1Pipeline.ramp_fit - INFO - Step ramp_fit parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh', 'int_name': '', 'save_opt': False, 'opt_name': '', 'suppress_one_group': True, 'maximum_cores': 'none'}
2022-12-02 15:53:19,376 - stpipe.Detector1Pipeline.ramp_fit - INFO - Using READNOISE reference file: /grp/crds/cache/references/jwst/jwst_nirspec_readnoise_0018.fits
2022-12-02 15:53:19,377 - stpipe.Detector1Pipeline.ramp_fit - INFO - Using GAIN reference file: /grp/crds/cache/references/jwst/jwst_nirspec_gain_0019.fits
2022-12-02 15:53:19,494 - stpipe.Detector1Pipeline.ramp_fit - INFO - Using algorithm = ols
2022-12-02 15:53:19,495 - stpipe.Detector1Pipeline.ramp_fit - INFO - Using weighting = optimal
/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.9/site-packages/stcal/ramp_fitting/ols_fit.py:1089: RuntimeWarning: invalid value encountered in multiply
  var_p4[num_int, :, :, :] *= (segs_4[num_int, :, :, :] > 0)
2022-12-02 15:53:33,337 - stpipe.Detector1Pipeline.ramp_fit - INFO - Number of groups per integration: 4
2022-12-02 15:53:33,339 - stpipe.Detector1Pipeline.ramp_fit - INFO - Number of integrations: 1
2022-12-02 15:53:33,533 - stpipe.Detector1Pipeline.ramp_fit - INFO - Step ramp_fit done
2022-12-02 15:53:33,688 - stpipe.Detector1Pipeline.gain_scale - INFO - Step gain_scale running with args (<ImageModel(2048, 2048) from mos_prism_nrs1_uncal.fits>,).
2022-12-02 15:53:33,690 - stpipe.Detector1Pipeline.gain_scale - INFO - Step gain_scale parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': 'gain_scale', 'search_output_file': True, 'input_dir': '/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh'}
2022-12-02 15:53:33,759 - stpipe.Detector1Pipeline.gain_scale - INFO - GAINFACT not found in gain reference file
2022-12-02 15:53:33,760 - stpipe.Detector1Pipeline.gain_scale - INFO - Step will be skipped
2022-12-02 15:53:33,765 - stpipe.Detector1Pipeline.gain_scale - INFO - Step gain_scale done
2022-12-02 15:53:33,880 - stpipe.Detector1Pipeline.gain_scale - INFO - Step gain_scale running with args (<CubeModel(1, 2048, 2048) from mos_prism_nrs1_uncal.fits>,).
2022-12-02 15:53:33,882 - stpipe.Detector1Pipeline.gain_scale - INFO - Step gain_scale parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': 'gain_scaleints', 'search_output_file': True, 'input_dir': '/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh'}
2022-12-02 15:53:33,952 - stpipe.Detector1Pipeline.gain_scale - INFO - GAINFACT not found in gain reference file
2022-12-02 15:53:33,953 - stpipe.Detector1Pipeline.gain_scale - INFO - Step will be skipped
2022-12-02 15:53:33,958 - stpipe.Detector1Pipeline.gain_scale - INFO - Step gain_scale done
2022-12-02 15:53:33,959 - stpipe.Detector1Pipeline - INFO - ... ending calwebb_detector1
2022-12-02 15:53:33,959 - stpipe.Detector1Pipeline - INFO - Results used CRDS context: jwst_1019.pmap
2022-12-02 15:53:33,960 - stpipe.Detector1Pipeline - INFO - Step Detector1Pipeline done
2022-12-02 15:53:33,969 - stpipe.AssignWcsStep - INFO - AssignWcsStep instance created.
2022-12-02 15:53:34,079 - stpipe.AssignWcsStep - INFO - Step AssignWcsStep running with args (<ImageModel(2048, 2048) from mos_prism_nrs1_uncal.fits>,).
2022-12-02 15:53:34,081 - stpipe.AssignWcsStep - INFO - Step AssignWcsStep parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'sip_approx': True, 'sip_max_pix_error': 0.1, 'sip_degree': None, 'sip_max_inv_pix_error': 0.1, 'sip_inv_degree': None, 'sip_npoints': 12, 'slit_y_low': -0.55, 'slit_y_high': 0.55}
2022-12-02 15:53:34,222 - stpipe.AssignWcsStep - INFO - Retrieving open MSA slitlets for msa_metadata_id = 1 and dither_index = 1
2022-12-02 15:53:34,266 - stpipe.AssignWcsStep - INFO - gwa_ytilt is 0.0332140289247036 deg
2022-12-02 15:53:34,267 - stpipe.AssignWcsStep - INFO - gwa_xtilt is 0.3367482721805573 deg
2022-12-02 15:53:34,268 - stpipe.AssignWcsStep - INFO - theta_y correction: -1.0907214098475986e-05 deg
2022-12-02 15:53:34,269 - stpipe.AssignWcsStep - INFO - theta_x correction: 0.0 deg
2022-12-02 15:53:34,594 - stpipe.AssignWcsStep - INFO - Slits projected on detector NRS1: [3, 4]
2022-12-02 15:53:34,595 - stpipe.AssignWcsStep - INFO - Computing WCS for 2 open slitlets
2022-12-02 15:53:34,632 - stpipe.AssignWcsStep - INFO - gwa_ytilt is 0.0332140289247036 deg
2022-12-02 15:53:34,633 - stpipe.AssignWcsStep - INFO - gwa_xtilt is 0.3367482721805573 deg
2022-12-02 15:53:34,634 - stpipe.AssignWcsStep - INFO - theta_y correction: -1.0907214098475986e-05 deg
2022-12-02 15:53:34,636 - stpipe.AssignWcsStep - INFO - theta_x correction: 0.0 deg
2022-12-02 15:53:34,650 - stpipe.AssignWcsStep - INFO - SPORDER= 0, wrange=[6e-07, 5.3e-06]
2022-12-02 15:53:34,802 - stpipe.AssignWcsStep - INFO - There are 0 open slits in quadrant 1
2022-12-02 15:53:34,803 - stpipe.AssignWcsStep - INFO - There are 0 open slits in quadrant 2
2022-12-02 15:53:34,803 - stpipe.AssignWcsStep - INFO - There are 1 open slits in quadrant 3
2022-12-02 15:53:34,812 - stpipe.AssignWcsStep - INFO - There are 1 open slits in quadrant 4
2022-12-02 15:53:34,821 - stpipe.AssignWcsStep - INFO - There are 0 open slits in quadrant 5
2022-12-02 15:53:34,986 - stpipe.AssignWcsStep - INFO - Created a NIRSPEC nrs_msaspec pipeline with references {'distortion': None, 'filteroffset': None, 'specwcs': None, 'regions': None, 'wavelengthrange': '/grp/crds/cache/references/jwst/jwst_nirspec_wavelengthrange_0004.asdf', 'camera': '/grp/crds/cache/references/jwst/jwst_nirspec_camera_0004.asdf', 'collimator': '/grp/crds/cache/references/jwst/jwst_nirspec_collimator_0004.asdf', 'disperser': '/grp/crds/cache/references/jwst/jwst_nirspec_disperser_0034.asdf', 'fore': '/grp/crds/cache/references/jwst/jwst_nirspec_fore_0028.asdf', 'fpa': '/grp/crds/cache/references/jwst/jwst_nirspec_fpa_0005.asdf', 'msa': '/grp/crds/cache/references/jwst/jwst_nirspec_msa_0005.asdf', 'ote': '/grp/crds/cache/references/jwst/jwst_nirspec_ote_0005.asdf', 'ifupost': None, 'ifufore': None, 'ifuslicer': None, 'msametafile': '/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh/V0030006000104_msa.fits'}
2022-12-02 15:53:35,177 - stpipe.AssignWcsStep - INFO - COMPLETED assign_wcs
2022-12-02 15:53:35,191 - stpipe.AssignWcsStep - INFO - Results used CRDS context: jwst_1019.pmap
2022-12-02 15:53:35,192 - stpipe.AssignWcsStep - INFO - Step AssignWcsStep done
2022-12-02 15:53:35,201 - stpipe.MSAFlagOpenStep - INFO - MSAFlagOpenStep instance created.
2022-12-02 15:53:35,336 - stpipe.MSAFlagOpenStep - INFO - Step MSAFlagOpenStep running with args (<ImageModel(2048, 2048) from mos_prism_nrs1_uncal.fits>,).
2022-12-02 15:53:35,338 - stpipe.MSAFlagOpenStep - INFO - Step MSAFlagOpenStep parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}
2022-12-02 15:53:35,355 - stpipe.MSAFlagOpenStep - INFO - Using reference file /grp/crds/cache/references/jwst/jwst_nirspec_msaoper_0001.json
2022-12-02 15:53:35,357 - stpipe.JwstStep - INFO - JwstStep instance created.
2022-12-02 15:53:35,526 - stpipe.MSAFlagOpenStep - INFO - gwa_ytilt is 0.0332140289247036 deg
2022-12-02 15:53:35,527 - stpipe.MSAFlagOpenStep - INFO - gwa_xtilt is 0.3367482721805573 deg
2022-12-02 15:53:35,528 - stpipe.MSAFlagOpenStep - INFO - theta_y correction: -1.0907214098475986e-05 deg
2022-12-02 15:53:35,530 - stpipe.MSAFlagOpenStep - INFO - theta_x correction: 0.0 deg
2022-12-02 15:53:35,544 - stpipe.MSAFlagOpenStep - INFO - SPORDER= 0, wrange=[6e-07, 5.3e-06]
2022-12-02 15:53:35,696 - stpipe.MSAFlagOpenStep - INFO - There are 5 open slits in quadrant 1
2022-12-02 15:53:35,744 - stpipe.MSAFlagOpenStep - INFO - There are 3 open slits in quadrant 2
2022-12-02 15:53:35,771 - stpipe.MSAFlagOpenStep - INFO - There are 9 open slits in quadrant 3
2022-12-02 15:53:35,847 - stpipe.MSAFlagOpenStep - INFO - There are 3 open slits in quadrant 4
2022-12-02 15:53:35,873 - stpipe.MSAFlagOpenStep - INFO - There are 0 open slits in quadrant 5
/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.9/site-packages/astropy/modeling/bounding_box.py:83: RuntimeWarning: Invalid interval: upper bound 2047.5 is strictly less than lower bound 2588.086193887466.
  warnings.warn(f"Invalid interval: upper bound {upper} "
/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.9/site-packages/astropy/modeling/bounding_box.py:83: RuntimeWarning: Invalid interval: upper bound 2047.5 is strictly less than lower bound 2332.7637849323596.
  warnings.warn(f"Invalid interval: upper bound {upper} "
/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.9/site-packages/astropy/modeling/bounding_box.py:83: RuntimeWarning: Invalid interval: upper bound 2047.5 is strictly less than lower bound 2734.225436305883.
  warnings.warn(f"Invalid interval: upper bound {upper} "
/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.9/site-packages/astropy/modeling/bounding_box.py:83: RuntimeWarning: Invalid interval: upper bound 2047.5 is strictly less than lower bound 2098.587600763162.
  warnings.warn(f"Invalid interval: upper bound {upper} "
/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.9/site-packages/astropy/modeling/bounding_box.py:83: RuntimeWarning: Invalid interval: upper bound 2047.5 is strictly less than lower bound 2088.836558573466.
  warnings.warn(f"Invalid interval: upper bound {upper} "
2022-12-02 15:53:46,925 - stpipe.MSAFlagOpenStep - INFO - Results used CRDS context: jwst_1019.pmap
2022-12-02 15:53:46,927 - stpipe.MSAFlagOpenStep - INFO - Step MSAFlagOpenStep done
2022-12-02 15:53:46,940 - stpipe.Extract2dStep - INFO - Extract2dStep instance created.
2022-12-02 15:53:47,190 - stpipe.Extract2dStep - INFO - Step Extract2dStep running with args (<ImageModel(2048, 2048) from mos_prism_nrs1_uncal.fits>,).
2022-12-02 15:53:47,192 - stpipe.Extract2dStep - INFO - Step Extract2dStep parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'slit_name': None, 'extract_orders': None, 'grism_objects': None, 'tsgrism_extract_height': None, 'wfss_extract_half_height': 5, 'wfss_mmag_extract': None, 'wfss_nbright': 1000}
2022-12-02 15:53:47,210 - stpipe.Extract2dStep - INFO - EXP_TYPE is NRS_MSASPEC
2022-12-02 15:53:47,380 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 3
2022-12-02 15:53:47,381 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 1027 1464
2022-12-02 15:53:47,382 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 1972 1983
2022-12-02 15:53:47,583 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2022-12-02 15:53:47,592 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.216281195 -45.702862740 156.216151591 -45.702738206 156.216089149 -45.702770462 156.216218751 -45.702894998
2022-12-02 15:53:47,594 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.216281195 -45.702862740 156.216151591 -45.702738206 156.216089149 -45.702770462 156.216218751 -45.702894998
2022-12-02 15:53:47,742 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 4
2022-12-02 15:53:47,744 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 1275 1699
2022-12-02 15:53:47,745 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 34 43
2022-12-02 15:53:48,019 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2022-12-02 15:53:48,031 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.168120618 -45.657220874 156.167995139 -45.657100409 156.167933468 -45.657132147 156.168058946 -45.657252613
2022-12-02 15:53:48,034 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.168120618 -45.657220874 156.167995139 -45.657100409 156.167933468 -45.657132147 156.168058946 -45.657252613
2022-12-02 15:53:48,156 - stpipe.Extract2dStep - INFO - Results used CRDS context: jwst_1019.pmap
2022-12-02 15:53:48,157 - stpipe.Extract2dStep - INFO - Step Extract2dStep done
2022-12-02 15:53:48,389 - stpipe.SourceTypeStep - INFO - SourceTypeStep instance created.
2022-12-02 15:53:48,696 - stpipe.SourceTypeStep - INFO - Step SourceTypeStep running with args (<MultiSlitModel from mos_prism_nrs1_uncal.fits>,).
2022-12-02 15:53:48,698 - stpipe.SourceTypeStep - INFO - Step SourceTypeStep parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'source_type': None}
2022-12-02 15:53:48,706 - stpipe.SourceTypeStep - INFO - Input EXP_TYPE is NRS_MSASPEC
2022-12-02 15:53:48,708 - stpipe.SourceTypeStep - INFO - source_id=3, stellarity=100.0000, type=POINT
2022-12-02 15:53:48,709 - stpipe.SourceTypeStep - INFO - source_id=4, stellarity=100.0000, type=POINT
2022-12-02 15:53:48,712 - stpipe.SourceTypeStep - INFO - Step SourceTypeStep done
2022-12-02 15:53:48,728 - stpipe.WavecorrStep - INFO - WavecorrStep instance created.
2022-12-02 15:53:49,024 - stpipe.WavecorrStep - INFO - Step WavecorrStep running with args (<MultiSlitModel from mos_prism_nrs1_uncal.fits>,).
2022-12-02 15:53:49,025 - stpipe.WavecorrStep - INFO - Step WavecorrStep parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}
2022-12-02 15:53:49,051 - stpipe.WavecorrStep - INFO - Using WAVECORR reference file /grp/crds/cache/references/jwst/jwst_nirspec_wavecorr_0004.asdf
2022-12-02 15:53:49,484 - stpipe.WavecorrStep - INFO - Detected a POINT source type in slit 3
2022-12-02 15:53:49,485 - stpipe.WavecorrStep - INFO - slit name 3
2022-12-02 15:53:49,564 - stpipe.WavecorrStep - INFO - Using wavelength zero-point correction for aperture MOS
2022-12-02 15:53:49,569 - stpipe.WavecorrStep - INFO - Detected a POINT source type in slit 4
2022-12-02 15:53:49,569 - stpipe.WavecorrStep - INFO - slit name 4
2022-12-02 15:53:49,638 - stpipe.WavecorrStep - INFO - Using wavelength zero-point correction for aperture MOS
2022-12-02 15:53:49,646 - stpipe.WavecorrStep - INFO - Results used CRDS context: jwst_1019.pmap
2022-12-02 15:53:49,647 - stpipe.WavecorrStep - INFO - Step WavecorrStep done
2022-12-02 15:53:49,663 - stpipe.FlatFieldStep - INFO - FlatFieldStep instance created.
2022-12-02 15:53:49,931 - stpipe.FlatFieldStep - INFO - Step FlatFieldStep running with args (<MultiSlitModel from mos_prism_nrs1_uncal.fits>,).
2022-12-02 15:53:49,933 - stpipe.FlatFieldStep - INFO - Step FlatFieldStep parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'save_interpolated_flat': False, 'user_supplied_flat': None, 'inverse': False}
2022-12-02 15:54:11,997 - stpipe.FlatFieldStep - INFO - Working on slit 3
2022-12-02 15:54:12,762 - stpipe.FlatFieldStep - INFO - Working on slit 4
2022-12-02 15:54:13,574 - stpipe.FlatFieldStep - INFO - Results used CRDS context: jwst_1019.pmap
2022-12-02 15:54:13,575 - stpipe.FlatFieldStep - INFO - Step FlatFieldStep done
2022-12-02 15:54:13,590 - stpipe.PathLossStep - INFO - PathLossStep instance created.
2022-12-02 15:54:13,774 - stpipe.PathLossStep - INFO - Step PathLossStep running with args (<MultiSlitModel from mos_prism_nrs1_uncal.fits>,).
2022-12-02 15:54:13,776 - stpipe.PathLossStep - INFO - Step PathLossStep parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'inverse': False, 'source_type': None}
2022-12-02 15:54:13,799 - stpipe.PathLossStep - INFO - Using PATHLOSS reference file /grp/crds/cache/references/jwst/jwst_nirspec_pathloss_0002.fits
2022-12-02 15:54:13,873 - stpipe.PathLossStep - INFO - Input exposure type is NRS_MSASPEC
2022-12-02 15:54:14,282 - stpipe.PathLossStep - INFO - Working on slit 0
2022-12-02 15:54:14,302 - stpipe.PathLossStep - INFO - Working on slit 1
2022-12-02 15:54:14,327 - stpipe.PathLossStep - INFO - Results used CRDS context: jwst_1019.pmap
2022-12-02 15:54:14,328 - stpipe.PathLossStep - INFO - Step PathLossStep done
2022-12-02 15:54:14,341 - stpipe.BarShadowStep - INFO - BarShadowStep instance created.
2022-12-02 15:54:14,496 - stpipe.BarShadowStep - INFO - Step BarShadowStep running with args (<MultiSlitModel from mos_prism_nrs1_uncal.fits>,).
2022-12-02 15:54:14,498 - stpipe.BarShadowStep - INFO - Step BarShadowStep parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'inverse': False, 'source_type': None}
2022-12-02 15:54:14,520 - stpipe.BarShadowStep - INFO - Using BARSHADOW reference file /grp/crds/cache/references/jwst/jwst_nirspec_barshadow_0001.fits
2022-12-02 15:54:14,990 - stpipe.BarShadowStep - INFO - Working on slitlet 3
2022-12-02 15:54:15,002 - stpipe.BarShadowStep - INFO - Bar shadow correction skipped for slitlet 3 (source not uniform)
2022-12-02 15:54:15,009 - stpipe.BarShadowStep - INFO - Working on slitlet 4
2022-12-02 15:54:15,020 - stpipe.BarShadowStep - INFO - Bar shadow correction skipped for slitlet 4 (source not uniform)
2022-12-02 15:54:15,031 - stpipe.BarShadowStep - INFO - Results used CRDS context: jwst_1019.pmap
2022-12-02 15:54:15,031 - stpipe.BarShadowStep - INFO - Step BarShadowStep done

Looping over open slitlets...
Working with slitlet  3
Slitlet name in fits file previous to barshadow and in barshadow output file are the same.
Test for this slit is skipped since source is POINT and hence, the correction is not applied.

Working with slitlet  4
Slitlet name in fits file previous to barshadow and in barshadow output file are the same.
Test for this slit is skipped since source is POINT and hence, the correction is not applied.


 * Test of barshadow_correction for slitlet 3  SKIPPED due to source=POINT. 
   Reported as PASSED since behavior is as expected.

 * Test of percentage_greater_3threshold for slitlet 3  SKIPPED due to source=POINT. 
   Reported as PASSED since behavior is as expected.

 * Test of percentage_greater_5threshold for slitlet 3  SKIPPED due to source=POINT. 
   Reported as PASSED since behavior is as expected.

 * Test of barshadow_correction for slitlet 4  SKIPPED due to source=POINT. 
   Reported as PASSED since behavior is as expected.

 * Test of percentage_greater_3threshold for slitlet 4  SKIPPED due to source=POINT. 
   Reported as PASSED since behavior is as expected.

 * Test of percentage_greater_5threshold for slitlet 4  SKIPPED due to source=POINT. 
   Reported as PASSED since behavior is as expected.

 *** Final result for barshadow test will be reported as PASSED *** 

('* Barshadow validation test took ', '0.00016927719116210938 seconds to finish.')
Did barshadow validation test passed?  True 


Testing files for detector:  nrs2

2022-12-02 15:54:15,630 - stpipe - INFO - PARS-DETECTOR1PIPELINE parameters found: /grp/crds/cache/references/jwst/jwst_nirspec_pars-detector1pipeline_0004.asdf

Working with uncal_file:  /internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh/mos_prism_nrs2_uncal.fits

2022-12-02 15:54:15,648 - stpipe.Detector1Pipeline - INFO - Detector1Pipeline instance created.
2022-12-02 15:54:15,650 - stpipe.Detector1Pipeline.group_scale - INFO - GroupScaleStep instance created.
2022-12-02 15:54:15,651 - stpipe.Detector1Pipeline.dq_init - INFO - DQInitStep instance created.
2022-12-02 15:54:15,652 - stpipe.Detector1Pipeline.saturation - INFO - SaturationStep instance created.
2022-12-02 15:54:15,653 - stpipe.Detector1Pipeline.ipc - INFO - IPCStep instance created.
2022-12-02 15:54:15,655 - stpipe.Detector1Pipeline.superbias - INFO - SuperBiasStep instance created.
2022-12-02 15:54:15,656 - stpipe.Detector1Pipeline.refpix - INFO - RefPixStep instance created.
2022-12-02 15:54:15,657 - stpipe.Detector1Pipeline.rscd - INFO - RscdStep instance created.
2022-12-02 15:54:15,658 - stpipe.Detector1Pipeline.firstframe - INFO - FirstFrameStep instance created.
2022-12-02 15:54:15,659 - stpipe.Detector1Pipeline.lastframe - INFO - LastFrameStep instance created.
2022-12-02 15:54:15,661 - stpipe.Detector1Pipeline.linearity - INFO - LinearityStep instance created.
2022-12-02 15:54:15,662 - stpipe.Detector1Pipeline.dark_current - INFO - DarkCurrentStep instance created.
2022-12-02 15:54:15,663 - stpipe.Detector1Pipeline.reset - INFO - ResetStep instance created.
2022-12-02 15:54:15,664 - stpipe.Detector1Pipeline.persistence - INFO - PersistenceStep instance created.
2022-12-02 15:54:15,666 - stpipe.Detector1Pipeline.jump - INFO - JumpStep instance created.
2022-12-02 15:54:15,667 - stpipe.Detector1Pipeline.ramp_fit - INFO - RampFitStep instance created.
2022-12-02 15:54:15,668 - stpipe.Detector1Pipeline.gain_scale - INFO - GainScaleStep instance created.
2022-12-02 15:54:15,837 - stpipe.Detector1Pipeline - INFO - Step Detector1Pipeline running with args ('/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh/mos_prism_nrs2_uncal.fits',).
2022-12-02 15:54:15,848 - stpipe.Detector1Pipeline - INFO - Step Detector1Pipeline parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'save_calibrated_ramp': False, 'steps': {'group_scale': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'dq_init': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'saturation': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'n_pix_grow_sat': 1}, 'ipc': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': True, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'superbias': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'refpix': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'odd_even_columns': True, 'use_side_ref_pixels': True, 'side_smoothing_length': 11, 'side_gain': 1.0, 'odd_even_rows': True}, 'rscd': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'type': 'baseline'}, 'firstframe': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'lastframe': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'linearity': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'dark_current': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'dark_output': None}, 'reset': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'persistence': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'input_trapsfilled': '', 'flag_pers_cutoff': 40.0, 'save_persistence': False, 'save_trapsfilled': True}, 'jump': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'rejection_threshold': 4.0, 'three_group_rejection_threshold': 6.0, 'four_group_rejection_threshold': 5.0, 'maximum_cores': 'none', 'flag_4_neighbors': True, 'max_jump_to_flag_neighbors': 1000.0, 'min_jump_to_flag_neighbors': 10.0, 'after_jump_flag_dn1': 0.0, 'after_jump_flag_time1': 0.0, 'after_jump_flag_dn2': 0.0, 'after_jump_flag_time2': 0.0, 'min_sat_area': 1.0, 'min_jump_area': 5.0, 'expand_factor': 2.0, 'use_ellipses': False, 'sat_required_snowball': True, 'expand_large_events': False}, 'ramp_fit': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'int_name': '', 'save_opt': False, 'opt_name': '', 'suppress_one_group': True, 'maximum_cores': 'none'}, 'gain_scale': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}}}
2022-12-02 15:54:16,032 - stpipe.Detector1Pipeline - INFO - Prefetching reference files for dataset: 'mos_prism_nrs2_uncal.fits' reftypes = ['dark', 'gain', 'linearity', 'mask', 'persat', 'readnoise', 'refpix', 'reset', 'rscd', 'saturation', 'superbias', 'trapdensity', 'trappars']
2022-12-02 15:54:16,044 - stpipe.Detector1Pipeline - INFO - Prefetch for DARK reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_dark_0087.fits'.
2022-12-02 15:54:16,047 - stpipe.Detector1Pipeline - INFO - Prefetch for GAIN reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_gain_0018.fits'.
2022-12-02 15:54:16,049 - stpipe.Detector1Pipeline - INFO - Prefetch for LINEARITY reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_linearity_0021.fits'.
2022-12-02 15:54:16,051 - stpipe.Detector1Pipeline - INFO - Prefetch for MASK reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_mask_0011.fits'.
2022-12-02 15:54:16,054 - stpipe.Detector1Pipeline - INFO - Prefetch for PERSAT reference file is 'N/A'.
2022-12-02 15:54:16,055 - stpipe.Detector1Pipeline - INFO - Prefetch for READNOISE reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_readnoise_0017.fits'.
2022-12-02 15:54:16,057 - stpipe.Detector1Pipeline - INFO - Prefetch for REFPIX reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_refpix_0020.fits'.
2022-12-02 15:54:16,058 - stpipe.Detector1Pipeline - INFO - Prefetch for RESET reference file is 'N/A'.
2022-12-02 15:54:16,059 - stpipe.Detector1Pipeline - INFO - Prefetch for RSCD reference file is 'N/A'.
2022-12-02 15:54:16,059 - stpipe.Detector1Pipeline - INFO - Prefetch for SATURATION reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_saturation_0021.fits'.
2022-12-02 15:54:16,061 - stpipe.Detector1Pipeline - INFO - Prefetch for SUPERBIAS reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_superbias_0114.fits'.
2022-12-02 15:54:16,063 - stpipe.Detector1Pipeline - INFO - Prefetch for TRAPDENSITY reference file is 'N/A'.
2022-12-02 15:54:16,063 - stpipe.Detector1Pipeline - INFO - Prefetch for TRAPPARS reference file is 'N/A'.
2022-12-02 15:54:16,064 - stpipe.Detector1Pipeline - INFO - Starting calwebb_detector1 ...
2022-12-02 15:54:16,583 - stpipe.Detector1Pipeline.group_scale - INFO - Step group_scale running with args (<RampModel(1, 4, 3200, 2048) from mos_prism_nrs2_uncal.fits>,).
2022-12-02 15:54:16,585 - stpipe.Detector1Pipeline.group_scale - INFO - Step group_scale parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh'}
2022-12-02 15:54:16,704 - stpipe.Detector1Pipeline.group_scale - INFO - NFRAMES and FRMDIVSR are equal; correction not needed
2022-12-02 15:54:16,705 - stpipe.Detector1Pipeline.group_scale - INFO - Step will be skipped
2022-12-02 15:54:16,707 - stpipe.Detector1Pipeline.group_scale - INFO - Step group_scale done
2022-12-02 15:54:16,885 - stpipe.Detector1Pipeline.dq_init - INFO - Step dq_init running with args (<RampModel(1, 4, 3200, 2048) from mos_prism_nrs2_uncal.fits>,).
2022-12-02 15:54:16,887 - stpipe.Detector1Pipeline.dq_init - INFO - Step dq_init parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh'}
2022-12-02 15:54:16,916 - stpipe.Detector1Pipeline.dq_init - INFO - Using MASK reference file /grp/crds/cache/references/jwst/jwst_nirspec_mask_0011.fits
2022-12-02 15:54:17,551 - stpipe.Detector1Pipeline.dq_init - INFO - Step dq_init done
2022-12-02 15:54:17,716 - stpipe.Detector1Pipeline.saturation - INFO - Step saturation running with args (<RampModel(1, 4, 3200, 2048) from mos_prism_nrs2_uncal.fits>,).
2022-12-02 15:54:17,717 - stpipe.Detector1Pipeline.saturation - INFO - Step saturation parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh', 'n_pix_grow_sat': 1}
2022-12-02 15:54:17,741 - stpipe.Detector1Pipeline.saturation - INFO - Using SATURATION reference file /grp/crds/cache/references/jwst/jwst_nirspec_saturation_0021.fits
2022-12-02 15:54:19,210 - stpipe.Detector1Pipeline.saturation - INFO - Detected 40672 saturated pixels
2022-12-02 15:54:19,238 - stpipe.Detector1Pipeline.saturation - INFO - Detected 0 A/D floor pixels
2022-12-02 15:54:19,262 - stpipe.Detector1Pipeline.saturation - INFO - Step saturation done
2022-12-02 15:54:19,431 - stpipe.Detector1Pipeline.ipc - INFO - Step ipc running with args (<RampModel(1, 4, 3200, 2048) from mos_prism_nrs2_uncal.fits>,).
2022-12-02 15:54:19,433 - stpipe.Detector1Pipeline.ipc - INFO - Step ipc parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': True, 'suffix': None, 'search_output_file': True, 'input_dir': '/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh'}
2022-12-02 15:54:19,433 - stpipe.Detector1Pipeline.ipc - INFO - Step skipped.
2022-12-02 15:54:19,436 - stpipe.Detector1Pipeline.ipc - INFO - Step ipc done
2022-12-02 15:54:19,597 - stpipe.Detector1Pipeline.superbias - INFO - Step superbias running with args (<RampModel(1, 4, 3200, 2048) from mos_prism_nrs2_uncal.fits>,).
2022-12-02 15:54:19,598 - stpipe.Detector1Pipeline.superbias - INFO - Step superbias parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh'}
2022-12-02 15:54:19,629 - stpipe.Detector1Pipeline.superbias - INFO - Using SUPERBIAS reference file /grp/crds/cache/references/jwst/jwst_nirspec_superbias_0114.fits
/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.9/site-packages/stdatamodels/validate.py:38: ValidationWarning: While validating meta.exposure.readpatt the following error occurred:
'ALLIRS2' is not one of ['ACQ1', 'ACQ2', 'BRIGHT1', 'BRIGHT2', 'DEEP2', 'DEEP8', 'FAST', 'FASTGRPAVG', 'FASTGRPAVG8', 'FASTGRPAVG16', 'FASTGRPAVG32', 'FASTGRPAVG64', 'FASTR1', 'FASTR100', 'FGS', 'FGS60', 'FGS8370', 'FGS840', 'FGSRAPID', 'FINEGUIDE', 'ID', 'MEDIUM2', 'MEDIUM8', 'NIS', 'NISRAPID', 'NRS', 'NRSIRS2', 'NRSN16R4', 'NRSN32R8', 'NRSN8R2', 'NRSRAPID', 'NRSIRS2RAPID', 'NRSRAPIDD1', 'NRSRAPIDD2', 'NRSRAPIDD6', 'NRSSLOW', 'RAPID', 'SHALLOW2', 'SHALLOW4', 'SLOW', 'SLOWR1', 'TRACK', 'ANY', 'N/A']

Failed validating 'enum' in schema:
    OrderedDict([('title', 'Readout pattern'),
                 ('type', 'string'),
                 ('enum',
                  ['ACQ1',
                   'ACQ2',
                   'BRIGHT1',
                   'BRIGHT2',
                   'DEEP2',
                   'DEEP8',
                   'FAST',
                   'FASTGRPAVG',
                   'FASTGRPAVG8',
                   'FASTGRPAVG16',
                   'FASTGRPAVG32',
                   'FASTGRPAVG64',
                   'FASTR1',
                   'FASTR100',
                   'FGS',
                   'FGS60',
                   'FGS8370',
                   'FGS840',
                   'FGSRAPID',
                   'FINEGUIDE',
                   'ID',
                   'MEDIUM2',
                   'MEDIUM8',
                   'NIS',
                   'NISRAPID',
                   'NRS',
                   'NRSIRS2',
                   'NRSN16R4',
                   'NRSN32R8',
                   'NRSN8R2',
                   'NRSRAPID',
                   'NRSIRS2RAPID',
                   'NRSRAPIDD1',
                   'NRSRAPIDD2',
                   'NRSRAPIDD6',
                   'NRSSLOW',
                   'RAPID',
                   'SHALLOW2',
                   'SHALLOW4',
                   'SLOW',
                   'SLOWR1',
                   'TRACK',
                   'ANY',
                   'N/A']),
                 ('fits_ke ...
  warnings.warn(errmsg, ValidationWarning)
2022-12-02 15:54:22,436 - stpipe.Detector1Pipeline.superbias - INFO - Step superbias done
2022-12-02 15:54:22,743 - stpipe.Detector1Pipeline.refpix - INFO - Step refpix running with args (<RampModel(1, 4, 3200, 2048) from mos_prism_nrs2_uncal.fits>,).
2022-12-02 15:54:22,745 - stpipe.Detector1Pipeline.refpix - INFO - Step refpix parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh', 'odd_even_columns': True, 'use_side_ref_pixels': True, 'side_smoothing_length': 11, 'side_gain': 1.0, 'odd_even_rows': True}
2022-12-02 15:54:22,769 - stpipe.Detector1Pipeline.refpix - INFO - Using refpix reference file: /grp/crds/cache/references/jwst/jwst_nirspec_refpix_0020.fits
2022-12-02 15:54:24,929 - stpipe.Detector1Pipeline.refpix - INFO - Working on integration 1
2022-12-02 15:54:42,347 - stpipe.Detector1Pipeline.refpix - INFO - Step refpix done
2022-12-02 15:54:42,873 - stpipe.Detector1Pipeline.linearity - INFO - Step linearity running with args (<RampModel(1, 4, 3200, 2048) from mos_prism_nrs2_uncal.fits>,).
2022-12-02 15:54:42,875 - stpipe.Detector1Pipeline.linearity - INFO - Step linearity parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh'}
2022-12-02 15:54:42,908 - stpipe.Detector1Pipeline.linearity - INFO - Using Linearity reference file /grp/crds/cache/references/jwst/jwst_nirspec_linearity_0021.fits
2022-12-02 15:54:47,017 - stpipe.Detector1Pipeline.linearity - INFO - Step linearity done
2022-12-02 15:54:47,218 - stpipe.Detector1Pipeline.dark_current - INFO - Step dark_current running with args (<RampModel(1, 4, 3200, 2048) from mos_prism_nrs2_uncal.fits>,).
2022-12-02 15:54:47,219 - stpipe.Detector1Pipeline.dark_current - INFO - Step dark_current parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh', 'dark_output': None}
2022-12-02 15:54:47,288 - stpipe.Detector1Pipeline.dark_current - INFO - Using DARK reference file /grp/crds/cache/references/jwst/jwst_nirspec_dark_0087.fits
2022-12-02 15:55:20,905 - stpipe.Detector1Pipeline.dark_current - INFO - Science data nints=1, ngroups=4, nframes=1, groupgap=0
2022-12-02 15:55:20,906 - stpipe.Detector1Pipeline.dark_current - INFO - Dark data nints=1, ngroups=65, nframes=1, groupgap=0
2022-12-02 15:55:21,501 - stpipe.Detector1Pipeline.dark_current - INFO - Step dark_current done
2022-12-02 15:55:21,887 - stpipe.Detector1Pipeline.jump - INFO - Step jump running with args (<RampModel(1, 4, 3200, 2048) from mos_prism_nrs2_uncal.fits>,).
2022-12-02 15:55:21,890 - stpipe.Detector1Pipeline.jump - INFO - Step jump parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh', 'rejection_threshold': 4.0, 'three_group_rejection_threshold': 6.0, 'four_group_rejection_threshold': 5.0, 'maximum_cores': 'none', 'flag_4_neighbors': True, 'max_jump_to_flag_neighbors': 1000.0, 'min_jump_to_flag_neighbors': 10.0, 'after_jump_flag_dn1': 0.0, 'after_jump_flag_time1': 0.0, 'after_jump_flag_dn2': 0.0, 'after_jump_flag_time2': 0.0, 'min_sat_area': 1.0, 'min_jump_area': 5.0, 'expand_factor': 2.0, 'use_ellipses': False, 'sat_required_snowball': True, 'expand_large_events': False}
2022-12-02 15:55:21,939 - stpipe.Detector1Pipeline.jump - INFO - CR rejection threshold = 4 sigma
2022-12-02 15:55:21,995 - stpipe.Detector1Pipeline.jump - INFO - Using GAIN reference file: /grp/crds/cache/references/jwst/jwst_nirspec_gain_0018.fits
2022-12-02 15:55:22,375 - stpipe.Detector1Pipeline.jump - INFO - Using READNOISE reference file: /grp/crds/cache/references/jwst/jwst_nirspec_readnoise_0017.fits
2022-12-02 15:55:23,502 - stpipe.Detector1Pipeline.jump - INFO - Executing two-point difference method
2022-12-02 15:55:23,553 - stpipe.Detector1Pipeline.jump - INFO - Working on integration 1:
/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.9/site-packages/stcal/jump/twopoint_difference.py:154: RuntimeWarning: All-NaN slice encountered
  max_ratio = np.nanmax(ratio, axis=0)
2022-12-02 15:55:25,169 - stpipe.Detector1Pipeline.jump - INFO - From highest outlier, two-point found 0 pixels with at least one CR from five or more groups.
2022-12-02 15:55:25,546 - stpipe.Detector1Pipeline.jump - INFO - Total elapsed time = 2.04193 sec
/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.9/site-packages/stcal/jump/jump.py:302: RuntimeWarning: invalid value encountered in divide
  data /= gain_2d
/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.9/site-packages/stcal/jump/jump.py:303: RuntimeWarning: invalid value encountered in divide
  err /= gain_2d
/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.9/site-packages/stcal/jump/jump.py:304: RuntimeWarning: invalid value encountered in divide
  readnoise_2d /= gain_2d
2022-12-02 15:55:25,605 - stpipe.Detector1Pipeline.jump - INFO - The execution time in seconds: 3.666013
2022-12-02 15:55:25,611 - stpipe.Detector1Pipeline.jump - INFO - Step jump done
2022-12-02 15:55:25,803 - stpipe.Detector1Pipeline.ramp_fit - INFO - Step ramp_fit running with args (<RampModel(1, 4, 3200, 2048) from mos_prism_nrs2_uncal.fits>,).
2022-12-02 15:55:25,805 - stpipe.Detector1Pipeline.ramp_fit - INFO - Step ramp_fit parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh', 'int_name': '', 'save_opt': False, 'opt_name': '', 'suppress_one_group': True, 'maximum_cores': 'none'}
2022-12-02 15:55:25,896 - stpipe.Detector1Pipeline.ramp_fit - INFO - Using READNOISE reference file: /grp/crds/cache/references/jwst/jwst_nirspec_readnoise_0017.fits
2022-12-02 15:55:25,897 - stpipe.Detector1Pipeline.ramp_fit - INFO - Using GAIN reference file: /grp/crds/cache/references/jwst/jwst_nirspec_gain_0018.fits
2022-12-02 15:55:26,012 - stpipe.Detector1Pipeline.ramp_fit - INFO - Using algorithm = ols
2022-12-02 15:55:26,013 - stpipe.Detector1Pipeline.ramp_fit - INFO - Using weighting = optimal
/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.9/site-packages/stcal/ramp_fitting/ols_fit.py:1089: RuntimeWarning: invalid value encountered in multiply
  var_p4[num_int, :, :, :] *= (segs_4[num_int, :, :, :] > 0)
2022-12-02 15:55:40,600 - stpipe.Detector1Pipeline.ramp_fit - INFO - Number of groups per integration: 4
2022-12-02 15:55:40,601 - stpipe.Detector1Pipeline.ramp_fit - INFO - Number of integrations: 1
2022-12-02 15:55:40,795 - stpipe.Detector1Pipeline.ramp_fit - INFO - Step ramp_fit done
2022-12-02 15:55:40,984 - stpipe.Detector1Pipeline.gain_scale - INFO - Step gain_scale running with args (<ImageModel(2048, 2048) from mos_prism_nrs2_uncal.fits>,).
2022-12-02 15:55:40,986 - stpipe.Detector1Pipeline.gain_scale - INFO - Step gain_scale parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': 'gain_scale', 'search_output_file': True, 'input_dir': '/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh'}
2022-12-02 15:55:41,062 - stpipe.Detector1Pipeline.gain_scale - INFO - GAINFACT not found in gain reference file
2022-12-02 15:55:41,063 - stpipe.Detector1Pipeline.gain_scale - INFO - Step will be skipped
2022-12-02 15:55:41,068 - stpipe.Detector1Pipeline.gain_scale - INFO - Step gain_scale done
2022-12-02 15:55:41,228 - stpipe.Detector1Pipeline.gain_scale - INFO - Step gain_scale running with args (<CubeModel(1, 2048, 2048) from mos_prism_nrs2_uncal.fits>,).
2022-12-02 15:55:41,230 - stpipe.Detector1Pipeline.gain_scale - INFO - Step gain_scale parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': 'gain_scaleints', 'search_output_file': True, 'input_dir': '/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh'}
2022-12-02 15:55:41,307 - stpipe.Detector1Pipeline.gain_scale - INFO - GAINFACT not found in gain reference file
2022-12-02 15:55:41,308 - stpipe.Detector1Pipeline.gain_scale - INFO - Step will be skipped
2022-12-02 15:55:41,313 - stpipe.Detector1Pipeline.gain_scale - INFO - Step gain_scale done
2022-12-02 15:55:41,314 - stpipe.Detector1Pipeline - INFO - ... ending calwebb_detector1
2022-12-02 15:55:41,314 - stpipe.Detector1Pipeline - INFO - Results used CRDS context: jwst_1019.pmap
2022-12-02 15:55:41,315 - stpipe.Detector1Pipeline - INFO - Step Detector1Pipeline done
2022-12-02 15:55:41,325 - stpipe.AssignWcsStep - INFO - AssignWcsStep instance created.
2022-12-02 15:55:41,503 - stpipe.AssignWcsStep - INFO - Step AssignWcsStep running with args (<ImageModel(2048, 2048) from mos_prism_nrs2_uncal.fits>,).
2022-12-02 15:55:41,505 - stpipe.AssignWcsStep - INFO - Step AssignWcsStep parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'sip_approx': True, 'sip_max_pix_error': 0.1, 'sip_degree': None, 'sip_max_inv_pix_error': 0.1, 'sip_inv_degree': None, 'sip_npoints': 12, 'slit_y_low': -0.55, 'slit_y_high': 0.55}
2022-12-02 15:55:41,697 - stpipe.AssignWcsStep - INFO - Retrieving open MSA slitlets for msa_metadata_id = 1 and dither_index = 1
2022-12-02 15:55:41,742 - stpipe.AssignWcsStep - INFO - gwa_ytilt is 0.0332140289247036 deg
2022-12-02 15:55:41,743 - stpipe.AssignWcsStep - INFO - gwa_xtilt is 0.3367482721805573 deg
2022-12-02 15:55:41,744 - stpipe.AssignWcsStep - INFO - theta_y correction: -1.0907214098475986e-05 deg
2022-12-02 15:55:41,745 - stpipe.AssignWcsStep - INFO - theta_x correction: 0.0 deg
2022-12-02 15:55:41,980 - stpipe.AssignWcsStep - INFO - Removing slit 3 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:55:42,020 - stpipe.AssignWcsStep - INFO - Removing slit 4 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:55:42,021 - stpipe.AssignWcsStep - INFO - Slits projected on detector NRS2: []
2022-12-02 15:55:42,022 - stpipe.AssignWcsStep - CRITICAL - No open slits fall on detector NRS2.

No open slits fall on detector  nrs2
Skipping test for this file. 

Did barshadow validation test passed?  skipped 


Testing files for detector:  nrs1

2022-12-02 15:55:42,791 - stpipe - INFO - PARS-DETECTOR1PIPELINE parameters found: /grp/crds/cache/references/jwst/jwst_nirspec_pars-detector1pipeline_0004.asdf
2022-12-02 15:55:42,809 - stpipe.Detector1Pipeline - INFO - Detector1Pipeline instance created.
2022-12-02 15:55:42,810 - stpipe.Detector1Pipeline.group_scale - INFO - GroupScaleStep instance created.
2022-12-02 15:55:42,812 - stpipe.Detector1Pipeline.dq_init - INFO - DQInitStep instance created.
2022-12-02 15:55:42,813 - stpipe.Detector1Pipeline.saturation - INFO - SaturationStep instance created.

Working with uncal_file:  /internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh/mos_g140m_line1_NRS1_uncal.fits

2022-12-02 15:55:42,814 - stpipe.Detector1Pipeline.ipc - INFO - IPCStep instance created.
2022-12-02 15:55:42,815 - stpipe.Detector1Pipeline.superbias - INFO - SuperBiasStep instance created.
2022-12-02 15:55:42,816 - stpipe.Detector1Pipeline.refpix - INFO - RefPixStep instance created.
2022-12-02 15:55:42,818 - stpipe.Detector1Pipeline.rscd - INFO - RscdStep instance created.
2022-12-02 15:55:42,819 - stpipe.Detector1Pipeline.firstframe - INFO - FirstFrameStep instance created.
2022-12-02 15:55:42,820 - stpipe.Detector1Pipeline.lastframe - INFO - LastFrameStep instance created.
2022-12-02 15:55:42,821 - stpipe.Detector1Pipeline.linearity - INFO - LinearityStep instance created.
2022-12-02 15:55:42,822 - stpipe.Detector1Pipeline.dark_current - INFO - DarkCurrentStep instance created.
2022-12-02 15:55:42,823 - stpipe.Detector1Pipeline.reset - INFO - ResetStep instance created.
2022-12-02 15:55:42,824 - stpipe.Detector1Pipeline.persistence - INFO - PersistenceStep instance created.
2022-12-02 15:55:42,826 - stpipe.Detector1Pipeline.jump - INFO - JumpStep instance created.
2022-12-02 15:55:42,827 - stpipe.Detector1Pipeline.ramp_fit - INFO - RampFitStep instance created.
2022-12-02 15:55:42,828 - stpipe.Detector1Pipeline.gain_scale - INFO - GainScaleStep instance created.
2022-12-02 15:55:43,000 - stpipe.Detector1Pipeline - INFO - Step Detector1Pipeline running with args ('/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh/mos_g140m_line1_NRS1_uncal.fits',).
2022-12-02 15:55:43,010 - stpipe.Detector1Pipeline - INFO - Step Detector1Pipeline parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'save_calibrated_ramp': False, 'steps': {'group_scale': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'dq_init': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'saturation': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'n_pix_grow_sat': 1}, 'ipc': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': True, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'superbias': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'refpix': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'odd_even_columns': True, 'use_side_ref_pixels': True, 'side_smoothing_length': 11, 'side_gain': 1.0, 'odd_even_rows': True}, 'rscd': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'type': 'baseline'}, 'firstframe': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'lastframe': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'linearity': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'dark_current': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'dark_output': None}, 'reset': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}, 'persistence': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'input_trapsfilled': '', 'flag_pers_cutoff': 40.0, 'save_persistence': False, 'save_trapsfilled': True}, 'jump': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'rejection_threshold': 4.0, 'three_group_rejection_threshold': 6.0, 'four_group_rejection_threshold': 5.0, 'maximum_cores': 'none', 'flag_4_neighbors': True, 'max_jump_to_flag_neighbors': 1000.0, 'min_jump_to_flag_neighbors': 10.0, 'after_jump_flag_dn1': 0.0, 'after_jump_flag_time1': 0.0, 'after_jump_flag_dn2': 0.0, 'after_jump_flag_time2': 0.0, 'min_sat_area': 1.0, 'min_jump_area': 5.0, 'expand_factor': 2.0, 'use_ellipses': False, 'sat_required_snowball': True, 'expand_large_events': False}, 'ramp_fit': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'int_name': '', 'save_opt': False, 'opt_name': '', 'suppress_one_group': True, 'maximum_cores': 'none'}, 'gain_scale': {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}}}
2022-12-02 15:55:43,178 - stpipe.Detector1Pipeline - INFO - Prefetching reference files for dataset: 'mos_g140m_line1_NRS1_uncal.fits' reftypes = ['dark', 'gain', 'linearity', 'mask', 'persat', 'readnoise', 'refpix', 'reset', 'rscd', 'saturation', 'superbias', 'trapdensity', 'trappars']
2022-12-02 15:55:43,191 - stpipe.Detector1Pipeline - INFO - Prefetch for DARK reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_dark_0140.fits'.
2022-12-02 15:55:43,194 - stpipe.Detector1Pipeline - INFO - Prefetch for GAIN reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_gain_0019.fits'.
2022-12-02 15:55:43,197 - stpipe.Detector1Pipeline - INFO - Prefetch for LINEARITY reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_linearity_0019.fits'.
2022-12-02 15:55:43,199 - stpipe.Detector1Pipeline - INFO - Prefetch for MASK reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_mask_0024.fits'.
2022-12-02 15:55:43,203 - stpipe.Detector1Pipeline - INFO - Prefetch for PERSAT reference file is 'N/A'.
2022-12-02 15:55:43,203 - stpipe.Detector1Pipeline - INFO - Prefetch for READNOISE reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_readnoise_0019.fits'.
2022-12-02 15:55:43,207 - stpipe.Detector1Pipeline - INFO - Prefetch for REFPIX reference file is 'N/A'.
2022-12-02 15:55:43,207 - stpipe.Detector1Pipeline - INFO - Prefetch for RESET reference file is 'N/A'.
2022-12-02 15:55:43,207 - stpipe.Detector1Pipeline - INFO - Prefetch for RSCD reference file is 'N/A'.
2022-12-02 15:55:43,208 - stpipe.Detector1Pipeline - INFO - Prefetch for SATURATION reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_saturation_0023.fits'.
2022-12-02 15:55:43,210 - stpipe.Detector1Pipeline - INFO - Prefetch for SUPERBIAS reference file is '/grp/crds/cache/references/jwst/jwst_nirspec_superbias_0087.fits'.
2022-12-02 15:55:43,212 - stpipe.Detector1Pipeline - INFO - Prefetch for TRAPDENSITY reference file is 'N/A'.
2022-12-02 15:55:43,213 - stpipe.Detector1Pipeline - INFO - Prefetch for TRAPPARS reference file is 'N/A'.
2022-12-02 15:55:43,213 - stpipe.Detector1Pipeline - INFO - Starting calwebb_detector1 ...
2022-12-02 15:55:43,586 - stpipe.Detector1Pipeline.group_scale - INFO - Step group_scale running with args (<RampModel(1, 6, 2048, 2048) from mos_g140m_line1_NRS1_uncal.fits>,).
2022-12-02 15:55:43,588 - stpipe.Detector1Pipeline.group_scale - INFO - Step group_scale parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh'}
2022-12-02 15:55:43,696 - stpipe.Detector1Pipeline.group_scale - INFO - NFRAMES and FRMDIVSR are equal; correction not needed
2022-12-02 15:55:43,696 - stpipe.Detector1Pipeline.group_scale - INFO - Step will be skipped
2022-12-02 15:55:43,699 - stpipe.Detector1Pipeline.group_scale - INFO - Step group_scale done
2022-12-02 15:55:43,861 - stpipe.Detector1Pipeline.dq_init - INFO - Step dq_init running with args (<RampModel(1, 6, 2048, 2048) from mos_g140m_line1_NRS1_uncal.fits>,).
2022-12-02 15:55:43,863 - stpipe.Detector1Pipeline.dq_init - INFO - Step dq_init parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh'}
2022-12-02 15:55:43,886 - stpipe.Detector1Pipeline.dq_init - INFO - Using MASK reference file /grp/crds/cache/references/jwst/jwst_nirspec_mask_0024.fits
2022-12-02 15:55:44,523 - stpipe.Detector1Pipeline.dq_init - INFO - Step dq_init done
2022-12-02 15:55:44,683 - stpipe.Detector1Pipeline.saturation - INFO - Step saturation running with args (<RampModel(1, 6, 2048, 2048) from mos_g140m_line1_NRS1_uncal.fits>,).
2022-12-02 15:55:44,685 - stpipe.Detector1Pipeline.saturation - INFO - Step saturation parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh', 'n_pix_grow_sat': 1}
2022-12-02 15:55:44,708 - stpipe.Detector1Pipeline.saturation - INFO - Using SATURATION reference file /grp/crds/cache/references/jwst/jwst_nirspec_saturation_0023.fits
2022-12-02 15:55:46,132 - stpipe.Detector1Pipeline.saturation - INFO - Detected 108240 saturated pixels
2022-12-02 15:55:46,154 - stpipe.Detector1Pipeline.saturation - INFO - Detected 0 A/D floor pixels
2022-12-02 15:55:46,166 - stpipe.Detector1Pipeline.saturation - INFO - Step saturation done
2022-12-02 15:55:46,316 - stpipe.Detector1Pipeline.ipc - INFO - Step ipc running with args (<RampModel(1, 6, 2048, 2048) from mos_g140m_line1_NRS1_uncal.fits>,).
2022-12-02 15:55:46,318 - stpipe.Detector1Pipeline.ipc - INFO - Step ipc parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': True, 'suffix': None, 'search_output_file': True, 'input_dir': '/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh'}
2022-12-02 15:55:46,318 - stpipe.Detector1Pipeline.ipc - INFO - Step skipped.
2022-12-02 15:55:46,321 - stpipe.Detector1Pipeline.ipc - INFO - Step ipc done
2022-12-02 15:55:46,468 - stpipe.Detector1Pipeline.superbias - INFO - Step superbias running with args (<RampModel(1, 6, 2048, 2048) from mos_g140m_line1_NRS1_uncal.fits>,).
2022-12-02 15:55:46,470 - stpipe.Detector1Pipeline.superbias - INFO - Step superbias parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh'}
2022-12-02 15:55:46,495 - stpipe.Detector1Pipeline.superbias - INFO - Using SUPERBIAS reference file /grp/crds/cache/references/jwst/jwst_nirspec_superbias_0087.fits
2022-12-02 15:55:47,299 - stpipe.Detector1Pipeline.superbias - INFO - Step superbias done
2022-12-02 15:55:47,462 - stpipe.Detector1Pipeline.refpix - INFO - Step refpix running with args (<RampModel(1, 6, 2048, 2048) from mos_g140m_line1_NRS1_uncal.fits>,).
2022-12-02 15:55:47,464 - stpipe.Detector1Pipeline.refpix - INFO - Step refpix parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh', 'odd_even_columns': True, 'use_side_ref_pixels': True, 'side_smoothing_length': 11, 'side_gain': 1.0, 'odd_even_rows': True}
2022-12-02 15:55:47,571 - stpipe.Detector1Pipeline.refpix - INFO - NIR full frame data
2022-12-02 15:55:47,572 - stpipe.Detector1Pipeline.refpix - INFO - The following parameters are valid for this mode:
2022-12-02 15:55:47,573 - stpipe.Detector1Pipeline.refpix - INFO - use_side_ref_pixels = True
2022-12-02 15:55:47,573 - stpipe.Detector1Pipeline.refpix - INFO - odd_even_columns = True
2022-12-02 15:55:47,574 - stpipe.Detector1Pipeline.refpix - INFO - side_smoothing_length = 11
2022-12-02 15:55:47,574 - stpipe.Detector1Pipeline.refpix - INFO - side_gain = 1.0
2022-12-02 15:55:47,575 - stpipe.Detector1Pipeline.refpix - INFO - The following parameter is not applicable and is ignored:
2022-12-02 15:55:47,575 - stpipe.Detector1Pipeline.refpix - INFO - odd_even_rows = False
2022-12-02 15:55:49,984 - stpipe.Detector1Pipeline.refpix - INFO - Step refpix done
2022-12-02 15:55:50,140 - stpipe.Detector1Pipeline.linearity - INFO - Step linearity running with args (<RampModel(1, 6, 2048, 2048) from mos_g140m_line1_NRS1_uncal.fits>,).
2022-12-02 15:55:50,142 - stpipe.Detector1Pipeline.linearity - INFO - Step linearity parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh'}
2022-12-02 15:55:50,167 - stpipe.Detector1Pipeline.linearity - INFO - Using Linearity reference file /grp/crds/cache/references/jwst/jwst_nirspec_linearity_0019.fits
2022-12-02 15:55:52,587 - stpipe.Detector1Pipeline.linearity - INFO - Step linearity done
2022-12-02 15:55:52,748 - stpipe.Detector1Pipeline.dark_current - INFO - Step dark_current running with args (<RampModel(1, 6, 2048, 2048) from mos_g140m_line1_NRS1_uncal.fits>,).
2022-12-02 15:55:52,749 - stpipe.Detector1Pipeline.dark_current - INFO - Step dark_current parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh', 'dark_output': None}
2022-12-02 15:55:52,773 - stpipe.Detector1Pipeline.dark_current - INFO - Using DARK reference file /grp/crds/cache/references/jwst/jwst_nirspec_dark_0140.fits
2022-12-02 15:55:55,063 - stpipe.Detector1Pipeline.dark_current - INFO - Science data nints=1, ngroups=6, nframes=1, groupgap=0
2022-12-02 15:55:55,064 - stpipe.Detector1Pipeline.dark_current - INFO - Dark data nints=1, ngroups=10, nframes=1, groupgap=0
2022-12-02 15:55:55,344 - stpipe.Detector1Pipeline.dark_current - INFO - Step dark_current done
2022-12-02 15:55:55,503 - stpipe.Detector1Pipeline.jump - INFO - Step jump running with args (<RampModel(1, 6, 2048, 2048) from mos_g140m_line1_NRS1_uncal.fits>,).
2022-12-02 15:55:55,505 - stpipe.Detector1Pipeline.jump - INFO - Step jump parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh', 'rejection_threshold': 4.0, 'three_group_rejection_threshold': 6.0, 'four_group_rejection_threshold': 5.0, 'maximum_cores': 'none', 'flag_4_neighbors': True, 'max_jump_to_flag_neighbors': 1000.0, 'min_jump_to_flag_neighbors': 10.0, 'after_jump_flag_dn1': 0.0, 'after_jump_flag_time1': 0.0, 'after_jump_flag_dn2': 0.0, 'after_jump_flag_time2': 0.0, 'min_sat_area': 1.0, 'min_jump_area': 5.0, 'expand_factor': 2.0, 'use_ellipses': False, 'sat_required_snowball': True, 'expand_large_events': False}
2022-12-02 15:55:55,515 - stpipe.Detector1Pipeline.jump - INFO - CR rejection threshold = 4 sigma
2022-12-02 15:55:55,528 - stpipe.Detector1Pipeline.jump - INFO - Using GAIN reference file: /grp/crds/cache/references/jwst/jwst_nirspec_gain_0019.fits
2022-12-02 15:55:55,598 - stpipe.Detector1Pipeline.jump - INFO - Using READNOISE reference file: /grp/crds/cache/references/jwst/jwst_nirspec_readnoise_0019.fits
2022-12-02 15:55:56,097 - stpipe.Detector1Pipeline.jump - INFO - Executing two-point difference method
2022-12-02 15:55:56,137 - stpipe.Detector1Pipeline.jump - INFO - Working on integration 1:
/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.9/site-packages/stcal/jump/twopoint_difference.py:154: RuntimeWarning: All-NaN slice encountered
  max_ratio = np.nanmax(ratio, axis=0)
2022-12-02 15:55:58,357 - stpipe.Detector1Pipeline.jump - INFO - From highest outlier, two-point found 41569 pixels with at least one CR from five or more groups.
2022-12-02 15:56:05,272 - stpipe.Detector1Pipeline.jump - INFO - Total elapsed time = 9.17382 sec
/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.9/site-packages/stcal/jump/jump.py:302: RuntimeWarning: invalid value encountered in divide
  data /= gain_2d
/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.9/site-packages/stcal/jump/jump.py:303: RuntimeWarning: invalid value encountered in divide
  err /= gain_2d
/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.9/site-packages/stcal/jump/jump.py:304: RuntimeWarning: invalid value encountered in divide
  readnoise_2d /= gain_2d
2022-12-02 15:56:05,358 - stpipe.Detector1Pipeline.jump - INFO - The execution time in seconds: 9.842595
2022-12-02 15:56:05,363 - stpipe.Detector1Pipeline.jump - INFO - Step jump done
2022-12-02 15:56:05,515 - stpipe.Detector1Pipeline.ramp_fit - INFO - Step ramp_fit running with args (<RampModel(1, 6, 2048, 2048) from mos_g140m_line1_NRS1_uncal.fits>,).
2022-12-02 15:56:05,517 - stpipe.Detector1Pipeline.ramp_fit - INFO - Step ramp_fit parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh', 'int_name': '', 'save_opt': False, 'opt_name': '', 'suppress_one_group': True, 'maximum_cores': 'none'}
2022-12-02 15:56:05,553 - stpipe.Detector1Pipeline.ramp_fit - INFO - Using READNOISE reference file: /grp/crds/cache/references/jwst/jwst_nirspec_readnoise_0019.fits
2022-12-02 15:56:05,554 - stpipe.Detector1Pipeline.ramp_fit - INFO - Using GAIN reference file: /grp/crds/cache/references/jwst/jwst_nirspec_gain_0019.fits
2022-12-02 15:56:05,671 - stpipe.Detector1Pipeline.ramp_fit - INFO - Using algorithm = ols
2022-12-02 15:56:05,672 - stpipe.Detector1Pipeline.ramp_fit - INFO - Using weighting = optimal
/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.9/site-packages/stcal/ramp_fitting/ols_fit.py:1089: RuntimeWarning: invalid value encountered in multiply
  var_p4[num_int, :, :, :] *= (segs_4[num_int, :, :, :] > 0)
2022-12-02 15:56:30,894 - stpipe.Detector1Pipeline.ramp_fit - INFO - Number of groups per integration: 6
2022-12-02 15:56:30,895 - stpipe.Detector1Pipeline.ramp_fit - INFO - Number of integrations: 1
2022-12-02 15:56:31,051 - stpipe.Detector1Pipeline.ramp_fit - INFO - Step ramp_fit done
2022-12-02 15:56:31,225 - stpipe.Detector1Pipeline.gain_scale - INFO - Step gain_scale running with args (<ImageModel(2048, 2048) from mos_g140m_line1_NRS1_uncal.fits>,).
2022-12-02 15:56:31,227 - stpipe.Detector1Pipeline.gain_scale - INFO - Step gain_scale parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': 'gain_scale', 'search_output_file': True, 'input_dir': '/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh'}
2022-12-02 15:56:31,300 - stpipe.Detector1Pipeline.gain_scale - INFO - GAINFACT not found in gain reference file
2022-12-02 15:56:31,301 - stpipe.Detector1Pipeline.gain_scale - INFO - Step will be skipped
2022-12-02 15:56:31,306 - stpipe.Detector1Pipeline.gain_scale - INFO - Step gain_scale done
2022-12-02 15:56:31,459 - stpipe.Detector1Pipeline.gain_scale - INFO - Step gain_scale running with args (<CubeModel(1, 2048, 2048) from mos_g140m_line1_NRS1_uncal.fits>,).
2022-12-02 15:56:31,461 - stpipe.Detector1Pipeline.gain_scale - INFO - Step gain_scale parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': 'gain_scaleints', 'search_output_file': True, 'input_dir': '/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/tmp/tmpadvtl9hh'}
2022-12-02 15:56:31,532 - stpipe.Detector1Pipeline.gain_scale - INFO - GAINFACT not found in gain reference file
2022-12-02 15:56:31,533 - stpipe.Detector1Pipeline.gain_scale - INFO - Step will be skipped
2022-12-02 15:56:31,538 - stpipe.Detector1Pipeline.gain_scale - INFO - Step gain_scale done
2022-12-02 15:56:31,539 - stpipe.Detector1Pipeline - INFO - ... ending calwebb_detector1
2022-12-02 15:56:31,539 - stpipe.Detector1Pipeline - INFO - Results used CRDS context: jwst_1019.pmap
2022-12-02 15:56:31,539 - stpipe.Detector1Pipeline - INFO - Step Detector1Pipeline done
2022-12-02 15:56:31,549 - stpipe.AssignWcsStep - INFO - AssignWcsStep instance created.
2022-12-02 15:56:31,700 - stpipe.AssignWcsStep - INFO - Step AssignWcsStep running with args (<ImageModel(2048, 2048) from mos_g140m_line1_NRS1_uncal.fits>,).
2022-12-02 15:56:31,702 - stpipe.AssignWcsStep - INFO - Step AssignWcsStep parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'sip_approx': True, 'sip_max_pix_error': 0.1, 'sip_degree': None, 'sip_max_inv_pix_error': 0.1, 'sip_inv_degree': None, 'sip_npoints': 12, 'slit_y_low': -0.55, 'slit_y_high': 0.55}
2022-12-02 15:56:31,874 - stpipe.AssignWcsStep - INFO - Retrieving open MSA slitlets for msa_metadata_id = 1 and dither_index = 1
2022-12-02 15:56:32,114 - stpipe.AssignWcsStep - INFO - gwa_ytilt is 0.1260581910610199 deg
2022-12-02 15:56:32,115 - stpipe.AssignWcsStep - INFO - gwa_xtilt is 0.3316612243652344 deg
2022-12-02 15:56:32,116 - stpipe.AssignWcsStep - INFO - theta_y correction: 0.0002496099796717191 deg
2022-12-02 15:56:32,117 - stpipe.AssignWcsStep - INFO - theta_x correction: 0.0 deg
2022-12-02 15:56:32,347 - stpipe.AssignWcsStep - INFO - Removing slit 6 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:32,360 - stpipe.AssignWcsStep - INFO - Removing slit 7 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:32,373 - stpipe.AssignWcsStep - INFO - Removing slit 8 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:32,386 - stpipe.AssignWcsStep - INFO - Removing slit 9 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:32,399 - stpipe.AssignWcsStep - INFO - Removing slit 10 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:32,411 - stpipe.AssignWcsStep - INFO - Removing slit 11 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:32,424 - stpipe.AssignWcsStep - INFO - Removing slit 14 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:32,436 - stpipe.AssignWcsStep - INFO - Removing slit 15 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:32,449 - stpipe.AssignWcsStep - INFO - Removing slit 16 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:32,461 - stpipe.AssignWcsStep - INFO - Removing slit 17 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:32,474 - stpipe.AssignWcsStep - INFO - Removing slit 18 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:32,487 - stpipe.AssignWcsStep - INFO - Removing slit 19 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:32,499 - stpipe.AssignWcsStep - INFO - Removing slit 21 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:32,512 - stpipe.AssignWcsStep - INFO - Removing slit 25 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:32,525 - stpipe.AssignWcsStep - INFO - Removing slit 26 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:32,537 - stpipe.AssignWcsStep - INFO - Removing slit 27 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:32,550 - stpipe.AssignWcsStep - INFO - Removing slit 29 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:32,563 - stpipe.AssignWcsStep - INFO - Removing slit 31 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:32,575 - stpipe.AssignWcsStep - INFO - Removing slit 32 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:32,587 - stpipe.AssignWcsStep - INFO - Removing slit 33 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:32,600 - stpipe.AssignWcsStep - INFO - Removing slit 35 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:32,612 - stpipe.AssignWcsStep - INFO - Removing slit 37 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:32,625 - stpipe.AssignWcsStep - INFO - Removing slit 38 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:32,638 - stpipe.AssignWcsStep - INFO - Removing slit 39 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:32,650 - stpipe.AssignWcsStep - INFO - Removing slit 41 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:32,687 - stpipe.AssignWcsStep - INFO - Removing slit 1 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:32,700 - stpipe.AssignWcsStep - INFO - Removing slit 2 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:32,712 - stpipe.AssignWcsStep - INFO - Removing slit 3 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:32,725 - stpipe.AssignWcsStep - INFO - Removing slit 4 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:32,737 - stpipe.AssignWcsStep - INFO - Removing slit 5 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:32,750 - stpipe.AssignWcsStep - INFO - Removing slit 12 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:32,762 - stpipe.AssignWcsStep - INFO - Removing slit 13 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:32,775 - stpipe.AssignWcsStep - INFO - Removing slit 20 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:32,788 - stpipe.AssignWcsStep - INFO - Removing slit 22 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:32,800 - stpipe.AssignWcsStep - INFO - Removing slit 23 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:32,813 - stpipe.AssignWcsStep - INFO - Removing slit 24 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:32,826 - stpipe.AssignWcsStep - INFO - Removing slit 28 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:32,839 - stpipe.AssignWcsStep - INFO - Removing slit 30 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:32,851 - stpipe.AssignWcsStep - INFO - Removing slit 34 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:32,864 - stpipe.AssignWcsStep - INFO - Removing slit 36 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:32,876 - stpipe.AssignWcsStep - INFO - Removing slit 40 from the list of open slits because the WCS bounding_box is completely outside the detector.
2022-12-02 15:56:33,165 - stpipe.AssignWcsStep - INFO - Slits projected on detector NRS1: [42, 43, 44, 45, 46, 47, 48, 49, 50, 51, 52, 53, 54, 55, 56, 57, 58, 59, 60, 61, 62, 63, 64, 65, 66, 67, 68]
2022-12-02 15:56:33,166 - stpipe.AssignWcsStep - INFO - Computing WCS for 27 open slitlets
2022-12-02 15:56:33,202 - stpipe.AssignWcsStep - INFO - gwa_ytilt is 0.1260581910610199 deg
2022-12-02 15:56:33,203 - stpipe.AssignWcsStep - INFO - gwa_xtilt is 0.3316612243652344 deg
2022-12-02 15:56:33,203 - stpipe.AssignWcsStep - INFO - theta_y correction: 0.0002496099796717191 deg
2022-12-02 15:56:33,205 - stpipe.AssignWcsStep - INFO - theta_x correction: 0.0 deg
2022-12-02 15:56:33,218 - stpipe.AssignWcsStep - INFO - SPORDER= -1, wrange=[9.7e-07, 1.89e-06]
2022-12-02 15:56:33,361 - stpipe.AssignWcsStep - INFO - There are 2 open slits in quadrant 1
2022-12-02 15:56:33,377 - stpipe.AssignWcsStep - INFO - There are 11 open slits in quadrant 2
2022-12-02 15:56:33,459 - stpipe.AssignWcsStep - INFO - There are 4 open slits in quadrant 3
2022-12-02 15:56:33,490 - stpipe.AssignWcsStep - INFO - There are 10 open slits in quadrant 4
2022-12-02 15:56:33,565 - stpipe.AssignWcsStep - INFO - There are 0 open slits in quadrant 5
2022-12-02 15:56:33,925 - stpipe.AssignWcsStep - INFO - Created a NIRSPEC nrs_msaspec pipeline with references {'distortion': None, 'filteroffset': None, 'specwcs': None, 'regions': None, 'wavelengthrange': '/grp/crds/cache/references/jwst/jwst_nirspec_wavelengthrange_0004.asdf', 'camera': '/grp/crds/cache/references/jwst/jwst_nirspec_camera_0004.asdf', 'collimator': '/grp/crds/cache/references/jwst/jwst_nirspec_collimator_0004.asdf', 'disperser': '/grp/crds/cache/references/jwst/jwst_nirspec_disperser_0032.asdf', 'fore': '/grp/crds/cache/references/jwst/jwst_nirspec_fore_0023.asdf', 'fpa': '/grp/crds/cache/references/jwst/jwst_nirspec_fpa_0005.asdf', 'msa': '/grp/crds/cache/references/jwst/jwst_nirspec_msa_0005.asdf', 'ote': '/grp/crds/cache/references/jwst/jwst_nirspec_ote_0005.asdf', 'ifupost': None, 'ifufore': None, 'ifuslicer': None, 'msametafile': 'V8460001000101_msa.fits'}
2022-12-02 15:56:34,617 - stpipe.AssignWcsStep - INFO - COMPLETED assign_wcs
2022-12-02 15:56:34,632 - stpipe.AssignWcsStep - INFO - Results used CRDS context: jwst_1019.pmap
2022-12-02 15:56:34,633 - stpipe.AssignWcsStep - INFO - Step AssignWcsStep done
2022-12-02 15:56:34,642 - stpipe.MSAFlagOpenStep - INFO - MSAFlagOpenStep instance created.
2022-12-02 15:56:34,842 - stpipe.MSAFlagOpenStep - INFO - Step MSAFlagOpenStep running with args (<ImageModel(2048, 2048) from mos_g140m_line1_NRS1_uncal.fits>,).
2022-12-02 15:56:34,844 - stpipe.MSAFlagOpenStep - INFO - Step MSAFlagOpenStep parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}
2022-12-02 15:56:34,861 - stpipe.MSAFlagOpenStep - INFO - Using reference file /grp/crds/cache/references/jwst/jwst_nirspec_msaoper_0001.json
2022-12-02 15:56:34,862 - stpipe.JwstStep - INFO - JwstStep instance created.
2022-12-02 15:56:34,984 - stpipe.MSAFlagOpenStep - INFO - gwa_ytilt is 0.1260581910610199 deg
2022-12-02 15:56:34,985 - stpipe.MSAFlagOpenStep - INFO - gwa_xtilt is 0.3316612243652344 deg
2022-12-02 15:56:34,985 - stpipe.MSAFlagOpenStep - INFO - theta_y correction: 0.0002496099796717191 deg
2022-12-02 15:56:34,987 - stpipe.MSAFlagOpenStep - INFO - theta_x correction: 0.0 deg
2022-12-02 15:56:35,000 - stpipe.MSAFlagOpenStep - INFO - SPORDER= -1, wrange=[9.7e-07, 1.89e-06]
2022-12-02 15:56:35,154 - stpipe.MSAFlagOpenStep - INFO - There are 5 open slits in quadrant 1
2022-12-02 15:56:35,194 - stpipe.MSAFlagOpenStep - INFO - There are 3 open slits in quadrant 2
2022-12-02 15:56:35,218 - stpipe.MSAFlagOpenStep - INFO - There are 9 open slits in quadrant 3
2022-12-02 15:56:35,288 - stpipe.MSAFlagOpenStep - INFO - There are 3 open slits in quadrant 4
2022-12-02 15:56:35,311 - stpipe.MSAFlagOpenStep - INFO - There are 0 open slits in quadrant 5
/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.9/site-packages/astropy/modeling/bounding_box.py:83: RuntimeWarning: Invalid interval: upper bound 2047.5 is strictly less than lower bound 2324.820049828629.
  warnings.warn(f"Invalid interval: upper bound {upper} "
/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.9/site-packages/astropy/modeling/bounding_box.py:83: RuntimeWarning: Invalid interval: upper bound 2047.5 is strictly less than lower bound 2244.599990785436.
  warnings.warn(f"Invalid interval: upper bound {upper} "
2022-12-02 15:56:46,936 - stpipe.MSAFlagOpenStep - INFO - Results used CRDS context: jwst_1019.pmap
2022-12-02 15:56:46,937 - stpipe.MSAFlagOpenStep - INFO - Step MSAFlagOpenStep done
2022-12-02 15:56:46,947 - stpipe.Extract2dStep - INFO - Extract2dStep instance created.
2022-12-02 15:56:47,292 - stpipe.Extract2dStep - INFO - Step Extract2dStep running with args (<ImageModel(2048, 2048) from mos_g140m_line1_NRS1_uncal.fits>,).
2022-12-02 15:56:47,294 - stpipe.Extract2dStep - INFO - Step Extract2dStep parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'slit_name': None, 'extract_orders': None, 'grism_objects': None, 'tsgrism_extract_height': None, 'wfss_extract_half_height': 5, 'wfss_mmag_extract': None, 'wfss_nbright': 1000}
2022-12-02 15:56:47,310 - stpipe.Extract2dStep - INFO - EXP_TYPE is NRS_MSASPEC
2022-12-02 15:56:47,758 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 53
2022-12-02 15:56:47,759 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 1542 2048
2022-12-02 15:56:47,759 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 1316 1326
2022-12-02 15:56:47,943 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2022-12-02 15:56:47,951 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.226123221 -45.673642180 156.225994086 -45.673519691 156.225931834 -45.673551545 156.226060967 -45.673674035
2022-12-02 15:56:47,952 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.226123221 -45.673642180 156.225994086 -45.673519691 156.225931834 -45.673551545 156.226060967 -45.673674035
2022-12-02 15:56:48,605 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 54
2022-12-02 15:56:48,606 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 1542 2048
2022-12-02 15:56:48,607 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 1306 1316
2022-12-02 15:56:48,790 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2022-12-02 15:56:48,799 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.225872406 -45.673404272 156.225743296 -45.673281804 156.225681049 -45.673313656 156.225810156 -45.673436124
2022-12-02 15:56:48,800 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.225872406 -45.673404272 156.225743296 -45.673281804 156.225681049 -45.673313656 156.225810156 -45.673436124
2022-12-02 15:56:49,463 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 42
2022-12-02 15:56:49,463 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 2018 2048
2022-12-02 15:56:49,464 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 546 555
2022-12-02 15:56:49,652 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2022-12-02 15:56:49,660 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.223646010 -45.647128995 156.223518121 -45.647008321 156.223456024 -45.647039957 156.223583911 -45.647160632
2022-12-02 15:56:49,662 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.223646010 -45.647128995 156.223518121 -45.647008321 156.223456024 -45.647039957 156.223583911 -45.647160632
2022-12-02 15:56:50,100 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 43
2022-12-02 15:56:50,101 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 1970 2048
2022-12-02 15:56:50,102 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 415 424
2022-12-02 15:56:50,286 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2022-12-02 15:56:50,295 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.218966486 -45.644829601 156.218838959 -45.644709141 156.218776943 -45.644740759 156.218904467 -45.644861220
2022-12-02 15:56:50,296 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.218966486 -45.644829601 156.218838959 -45.644709141 156.218776943 -45.644740759 156.218904467 -45.644861220
2022-12-02 15:56:50,993 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 44
2022-12-02 15:56:50,994 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 1969 2048
2022-12-02 15:56:50,994 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 405 414
2022-12-02 15:56:51,179 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2022-12-02 15:56:51,187 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.218718991 -45.644595818 156.218591488 -45.644475376 156.218529475 -45.644506992 156.218656977 -45.644627436
2022-12-02 15:56:51,189 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.218718991 -45.644595818 156.218591488 -45.644475376 156.218529475 -45.644506992 156.218656977 -45.644627436
2022-12-02 15:56:51,913 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 45
2022-12-02 15:56:51,914 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 1908 2048
2022-12-02 15:56:51,915 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 531 541
2022-12-02 15:56:52,101 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2022-12-02 15:56:52,110 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.219673020 -45.648613077 156.219545303 -45.648492383 156.219483265 -45.648524021 156.219610979 -45.648644716
2022-12-02 15:56:52,111 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.219673020 -45.648613077 156.219545303 -45.648492383 156.219483265 -45.648524021 156.219610979 -45.648644716
2022-12-02 15:56:52,564 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 46
2022-12-02 15:56:52,565 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 1882 2048
2022-12-02 15:56:52,566 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 203 213
2022-12-02 15:56:52,748 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2022-12-02 15:56:52,757 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.211127421 -45.641279813 156.211000463 -45.641159678 156.210938572 -45.641191268 156.211065527 -45.641311404
2022-12-02 15:56:52,758 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.211127421 -45.641279813 156.211000463 -45.641159678 156.210938572 -45.641191268 156.211065527 -45.641311404
2022-12-02 15:56:53,475 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 47
2022-12-02 15:56:53,476 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 1815 2048
2022-12-02 15:56:53,477 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 567 576
2022-12-02 15:56:53,663 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2022-12-02 15:56:53,672 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.217456055 -45.651006881 156.217328370 -45.650886079 156.217266356 -45.650917729 156.217394038 -45.651038531
2022-12-02 15:56:53,673 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.217456055 -45.651006881 156.217328370 -45.650886079 156.217266356 -45.650917729 156.217394038 -45.651038531
2022-12-02 15:56:54,123 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 48
2022-12-02 15:56:54,124 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 1815 2048
2022-12-02 15:56:54,124 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 562 571
2022-12-02 15:56:54,309 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2022-12-02 15:56:54,318 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.217332149 -45.650889654 156.217204477 -45.650768862 156.217142464 -45.650800511 156.217270135 -45.650921304
2022-12-02 15:56:54,319 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.217332149 -45.650889654 156.217204477 -45.650768862 156.217142464 -45.650800511 156.217270135 -45.650921304
2022-12-02 15:56:55,044 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 49
2022-12-02 15:56:55,045 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 1791 2048
2022-12-02 15:56:55,045 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 632 642
2022-12-02 15:56:55,231 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2022-12-02 15:56:55,240 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.218210913 -45.652969013 156.218083107 -45.652848076 156.218021073 -45.652879740 156.218148877 -45.653000678
2022-12-02 15:56:55,241 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.218210913 -45.652969013 156.218083107 -45.652848076 156.218021073 -45.652879740 156.218148877 -45.653000678
2022-12-02 15:56:55,683 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 50
2022-12-02 15:56:55,684 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 1774 2048
2022-12-02 15:56:55,684 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 239 249
2022-12-02 15:56:55,870 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2022-12-02 15:56:55,879 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.208399869 -45.643929179 156.208272959 -45.643808942 156.208211096 -45.643840541 156.208338005 -45.643960778
2022-12-02 15:56:55,880 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.208399869 -45.643929179 156.208272959 -45.643808942 156.208211096 -45.643840541 156.208338005 -45.643960778
2022-12-02 15:56:56,609 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 51
2022-12-02 15:56:56,610 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 1759 2048
2022-12-02 15:56:56,610 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 431 441
2022-12-02 15:56:56,799 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2022-12-02 15:56:56,808 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.212403238 -45.648718689 156.212275928 -45.648598111 156.212213993 -45.648629742 156.212341301 -45.648750320
2022-12-02 15:56:56,810 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.212403238 -45.648718689 156.212275928 -45.648598111 156.212213993 -45.648629742 156.212341301 -45.648750320
2022-12-02 15:56:57,252 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 52
2022-12-02 15:56:57,252 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 1722 2048
2022-12-02 15:56:57,253 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 804 814
2022-12-02 15:56:57,732 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2022-12-02 15:56:57,740 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.219947139 -45.658234585 156.219819020 -45.658113276 156.219756938 -45.658144979 156.219885055 -45.658266289
2022-12-02 15:56:57,742 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.219947139 -45.658234585 156.219819020 -45.658113276 156.219756938 -45.658144979 156.219885055 -45.658266289
2022-12-02 15:56:58,207 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 55
2022-12-02 15:56:58,208 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 1022 2048
2022-12-02 15:56:58,208 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 1416 1430
2022-12-02 15:56:58,401 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2022-12-02 15:56:58,410 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.211226719 -45.684941334 156.211098073 -45.684818233 156.211035880 -45.684850241 156.211164524 -45.684973343
2022-12-02 15:56:58,411 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.211226719 -45.684941334 156.211098073 -45.684818233 156.211035880 -45.684850241 156.211164524 -45.684973343
2022-12-02 15:56:59,172 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 65
2022-12-02 15:56:59,173 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 427 1893
2022-12-02 15:56:59,174 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 1252 1273
2022-12-02 15:56:59,384 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2022-12-02 15:56:59,394 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.187669449 -45.691221095 156.187541886 -45.691097893 156.187479754 -45.691130071 156.187607315 -45.691253274
2022-12-02 15:56:59,396 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.187669449 -45.691221095 156.187541886 -45.691097893 156.187479754 -45.691130071 156.187607315 -45.691253274
2022-12-02 15:56:59,967 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 66
2022-12-02 15:56:59,972 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 426 1892
2022-12-02 15:56:59,973 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 1453 1474
2022-12-02 15:57:00,227 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2022-12-02 15:57:00,236 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.192290190 -45.696194513 156.192162195 -45.696070854 156.192099979 -45.696103094 156.192227972 -45.696226755
2022-12-02 15:57:00,237 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.192290190 -45.696194513 156.192162195 -45.696070854 156.192099979 -45.696103094 156.192227972 -45.696226755
2022-12-02 15:57:01,050 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 68
2022-12-02 15:57:01,051 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 375 1842
2022-12-02 15:57:01,052 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 1477 1500
2022-12-02 15:57:01,262 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2022-12-02 15:57:01,271 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.191192483 -45.697686513 156.191064493 -45.697562756 156.191002259 -45.697595026 156.191130247 -45.697718784
2022-12-02 15:57:01,272 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.191192483 -45.697686513 156.191064493 -45.697562756 156.191002259 -45.697595026 156.191130247 -45.697718784
2022-12-02 15:57:01,736 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 56
2022-12-02 15:57:01,737 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 872 2048
2022-12-02 15:57:01,737 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 769 783
2022-12-02 15:57:01,932 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2022-12-02 15:57:01,942 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.191122501 -45.671742959 156.190995485 -45.671621176 156.190933579 -45.671653049 156.191060593 -45.671774833
2022-12-02 15:57:01,943 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.191122501 -45.671742959 156.190995485 -45.671621176 156.190933579 -45.671653049 156.191060593 -45.671774833
2022-12-02 15:57:02,763 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 57
2022-12-02 15:57:02,764 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 805 2048
2022-12-02 15:57:02,764 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 355 370
2022-12-02 15:57:02,961 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2022-12-02 15:57:02,970 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.179343124 -45.662963603 156.179216994 -45.662842617 156.179155236 -45.662874401 156.179281365 -45.662995389
2022-12-02 15:57:02,972 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.179343124 -45.662963603 156.179216994 -45.662842617 156.179155236 -45.662874401 156.179281365 -45.662995389
2022-12-02 15:57:03,431 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 58
2022-12-02 15:57:03,432 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 731 2048
2022-12-02 15:57:03,432 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 259 275
2022-12-02 15:57:03,629 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2022-12-02 15:57:03,638 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.174716949 -45.661919476 156.174591057 -45.661798624 156.174529324 -45.661830406 156.174655215 -45.661951259
2022-12-02 15:57:03,639 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.174716949 -45.661919476 156.174591057 -45.661798624 156.174529324 -45.661830406 156.174655215 -45.661951259
2022-12-02 15:57:04,448 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 59
2022-12-02 15:57:04,449 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 658 2048
2022-12-02 15:57:04,449 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 72 88
2022-12-02 15:57:04,649 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2022-12-02 15:57:04,658 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.167987333 -45.658726530 156.167861814 -45.658605973 156.167800128 -45.658637729 156.167925645 -45.658758288
2022-12-02 15:57:04,659 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.167987333 -45.658726530 156.167861814 -45.658605973 156.167800128 -45.658637729 156.167925645 -45.658758288
2022-12-02 15:57:05,194 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 60
2022-12-02 15:57:05,195 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 641 2048
2022-12-02 15:57:05,195 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 682 699
2022-12-02 15:57:05,390 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2022-12-02 15:57:05,399 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.181507045 -45.673611447 156.181380443 -45.673489678 156.181318559 -45.673521602 156.181445158 -45.673643373
2022-12-02 15:57:05,400 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.181507045 -45.673611447 156.181380443 -45.673489678 156.181318559 -45.673521602 156.181445158 -45.673643373
2022-12-02 15:57:06,232 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 61
2022-12-02 15:57:06,233 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 620 2048
2022-12-02 15:57:06,234 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 823 840
2022-12-02 15:57:06,433 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2022-12-02 15:57:06,442 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.184095390 -45.677365774 156.183968526 -45.677243686 156.183906587 -45.677275659 156.184033450 -45.677397747
2022-12-02 15:57:06,443 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.184095390 -45.677365774 156.183968526 -45.677243686 156.183906587 -45.677275659 156.184033450 -45.677397747
2022-12-02 15:57:06,898 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 62
2022-12-02 15:57:06,899 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 570 2032
2022-12-02 15:57:06,900 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 510 528
2022-12-02 15:57:07,100 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2022-12-02 15:57:07,109 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.175200333 -45.670700849 156.175074128 -45.670579384 156.175012293 -45.670611285 156.175138497 -45.670732752
2022-12-02 15:57:07,110 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.175200333 -45.670700849 156.175074128 -45.670579384 156.175012293 -45.670611285 156.175138497 -45.670732752
2022-12-02 15:57:07,569 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 63
2022-12-02 15:57:07,570 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 454 1915
2022-12-02 15:57:07,571 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 182 200
2022-12-02 15:57:07,772 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2022-12-02 15:57:07,781 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.163846800 -45.664818400 156.163721256 -45.664697497 156.163659498 -45.664729348 156.163785040 -45.664850252
2022-12-02 15:57:07,782 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.163846800 -45.664818400 156.163721256 -45.664697497 156.163659498 -45.664729348 156.163785040 -45.664850252
2022-12-02 15:57:08,637 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 64
2022-12-02 15:57:08,638 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 454 1915
2022-12-02 15:57:08,639 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 177 195
2022-12-02 15:57:08,838 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2022-12-02 15:57:08,847 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.163724974 -45.664701077 156.163599439 -45.664580184 156.163537682 -45.664612033 156.163663216 -45.664732928
2022-12-02 15:57:08,849 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.163724974 -45.664701077 156.163599439 -45.664580184 156.163537682 -45.664612033 156.163663216 -45.664732928
2022-12-02 15:57:09,298 - stpipe.Extract2dStep - INFO - Name of subarray extracted: 67
2022-12-02 15:57:09,299 - stpipe.Extract2dStep - INFO - Subarray x-extents are: 328 1789
2022-12-02 15:57:09,299 - stpipe.Extract2dStep - INFO - Subarray y-extents are: 131 150
2022-12-02 15:57:09,498 - stpipe.Extract2dStep - INFO - set slit_attributes completed
2022-12-02 15:57:09,508 - stpipe.Extract2dStep - INFO - Update S_REGION to POLYGON ICRS  156.158533940 -45.665758025 156.158408563 -45.665637125 156.158346784 -45.665669007 156.158472159 -45.665789909
2022-12-02 15:57:09,509 - stpipe.Extract2dStep - INFO - Updated S_REGION to POLYGON ICRS  156.158533940 -45.665758025 156.158408563 -45.665637125 156.158346784 -45.665669007 156.158472159 -45.665789909
2022-12-02 15:57:11,178 - stpipe.Extract2dStep - INFO - Results used CRDS context: jwst_1019.pmap
2022-12-02 15:57:11,179 - stpipe.Extract2dStep - INFO - Step Extract2dStep done
2022-12-02 15:57:13,823 - stpipe.SourceTypeStep - INFO - SourceTypeStep instance created.
2022-12-02 15:57:14,640 - stpipe.SourceTypeStep - INFO - Step SourceTypeStep running with args (<MultiSlitModel from mos_g140m_line1_NRS1_uncal.fits>,).
2022-12-02 15:57:14,642 - stpipe.SourceTypeStep - INFO - Step SourceTypeStep parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'source_type': None}
2022-12-02 15:57:14,653 - stpipe.SourceTypeStep - INFO - Input EXP_TYPE is NRS_MSASPEC
2022-12-02 15:57:14,654 - stpipe.SourceTypeStep - INFO - source_id=53, stellarity=0.0000, type=EXTENDED
2022-12-02 15:57:14,656 - stpipe.SourceTypeStep - INFO - source_id=54, stellarity=0.0000, type=EXTENDED
2022-12-02 15:57:14,657 - stpipe.SourceTypeStep - INFO - source_id=42, stellarity=0.0000, type=EXTENDED
2022-12-02 15:57:14,658 - stpipe.SourceTypeStep - INFO - source_id=43, stellarity=0.0000, type=EXTENDED
2022-12-02 15:57:14,660 - stpipe.SourceTypeStep - INFO - source_id=44, stellarity=0.0000, type=EXTENDED
2022-12-02 15:57:14,661 - stpipe.SourceTypeStep - INFO - source_id=45, stellarity=0.0000, type=EXTENDED
2022-12-02 15:57:14,662 - stpipe.SourceTypeStep - INFO - source_id=46, stellarity=0.0000, type=EXTENDED
2022-12-02 15:57:14,663 - stpipe.SourceTypeStep - INFO - source_id=47, stellarity=0.0000, type=EXTENDED
2022-12-02 15:57:14,664 - stpipe.SourceTypeStep - INFO - source_id=48, stellarity=0.0000, type=EXTENDED
2022-12-02 15:57:14,666 - stpipe.SourceTypeStep - INFO - source_id=49, stellarity=0.0000, type=EXTENDED
2022-12-02 15:57:14,667 - stpipe.SourceTypeStep - INFO - source_id=50, stellarity=0.0000, type=EXTENDED
2022-12-02 15:57:14,668 - stpipe.SourceTypeStep - INFO - source_id=51, stellarity=0.0000, type=EXTENDED
2022-12-02 15:57:14,669 - stpipe.SourceTypeStep - INFO - source_id=52, stellarity=0.0000, type=EXTENDED
2022-12-02 15:57:14,671 - stpipe.SourceTypeStep - INFO - source_id=55, stellarity=0.0000, type=EXTENDED
2022-12-02 15:57:14,672 - stpipe.SourceTypeStep - INFO - source_id=65, stellarity=0.0000, type=EXTENDED
2022-12-02 15:57:14,673 - stpipe.SourceTypeStep - INFO - source_id=66, stellarity=0.0000, type=EXTENDED
2022-12-02 15:57:14,674 - stpipe.SourceTypeStep - INFO - source_id=68, stellarity=0.0000, type=EXTENDED
2022-12-02 15:57:14,675 - stpipe.SourceTypeStep - INFO - source_id=56, stellarity=0.0000, type=EXTENDED
2022-12-02 15:57:14,676 - stpipe.SourceTypeStep - INFO - source_id=57, stellarity=0.0000, type=EXTENDED
2022-12-02 15:57:14,677 - stpipe.SourceTypeStep - INFO - source_id=58, stellarity=0.0000, type=EXTENDED
2022-12-02 15:57:14,679 - stpipe.SourceTypeStep - INFO - source_id=59, stellarity=0.0000, type=EXTENDED
2022-12-02 15:57:14,680 - stpipe.SourceTypeStep - INFO - source_id=60, stellarity=0.0000, type=EXTENDED
2022-12-02 15:57:14,681 - stpipe.SourceTypeStep - INFO - source_id=61, stellarity=0.0000, type=EXTENDED
2022-12-02 15:57:14,682 - stpipe.SourceTypeStep - INFO - source_id=62, stellarity=0.0000, type=EXTENDED
2022-12-02 15:57:14,683 - stpipe.SourceTypeStep - INFO - source_id=63, stellarity=0.0000, type=EXTENDED
2022-12-02 15:57:14,684 - stpipe.SourceTypeStep - INFO - source_id=64, stellarity=0.0000, type=EXTENDED
2022-12-02 15:57:14,685 - stpipe.SourceTypeStep - INFO - source_id=67, stellarity=0.0000, type=EXTENDED
2022-12-02 15:57:14,688 - stpipe.SourceTypeStep - INFO - Step SourceTypeStep done
2022-12-02 15:57:14,772 - stpipe.WavecorrStep - INFO - WavecorrStep instance created.
2022-12-02 15:57:15,240 - stpipe.WavecorrStep - INFO - Step WavecorrStep running with args (<MultiSlitModel from mos_g140m_line1_NRS1_uncal.fits>,).
2022-12-02 15:57:15,242 - stpipe.WavecorrStep - INFO - Step WavecorrStep parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': ''}
2022-12-02 15:57:15,304 - stpipe.WavecorrStep - INFO - Using WAVECORR reference file /grp/crds/cache/references/jwst/jwst_nirspec_wavecorr_0004.asdf
2022-12-02 15:57:20,409 - stpipe.WavecorrStep - INFO - Detected a EXTENDED source type in slit 53
2022-12-02 15:57:20,410 - stpipe.WavecorrStep - INFO - Detected a EXTENDED source type in slit 54
2022-12-02 15:57:20,411 - stpipe.WavecorrStep - INFO - Detected a EXTENDED source type in slit 42
2022-12-02 15:57:20,412 - stpipe.WavecorrStep - INFO - Detected a EXTENDED source type in slit 43
2022-12-02 15:57:20,412 - stpipe.WavecorrStep - INFO - Detected a EXTENDED source type in slit 44
2022-12-02 15:57:20,413 - stpipe.WavecorrStep - INFO - Detected a EXTENDED source type in slit 45
2022-12-02 15:57:20,413 - stpipe.WavecorrStep - INFO - Detected a EXTENDED source type in slit 46
2022-12-02 15:57:20,414 - stpipe.WavecorrStep - INFO - Detected a EXTENDED source type in slit 47
2022-12-02 15:57:20,414 - stpipe.WavecorrStep - INFO - Detected a EXTENDED source type in slit 48
2022-12-02 15:57:20,415 - stpipe.WavecorrStep - INFO - Detected a EXTENDED source type in slit 49
2022-12-02 15:57:20,415 - stpipe.WavecorrStep - INFO - Detected a EXTENDED source type in slit 50
2022-12-02 15:57:20,416 - stpipe.WavecorrStep - INFO - Detected a EXTENDED source type in slit 51
2022-12-02 15:57:20,416 - stpipe.WavecorrStep - INFO - Detected a EXTENDED source type in slit 52
2022-12-02 15:57:20,417 - stpipe.WavecorrStep - INFO - Detected a EXTENDED source type in slit 55
2022-12-02 15:57:20,417 - stpipe.WavecorrStep - INFO - Detected a EXTENDED source type in slit 65
2022-12-02 15:57:20,418 - stpipe.WavecorrStep - INFO - Detected a EXTENDED source type in slit 66
2022-12-02 15:57:20,418 - stpipe.WavecorrStep - INFO - Detected a EXTENDED source type in slit 68
2022-12-02 15:57:20,418 - stpipe.WavecorrStep - INFO - Detected a EXTENDED source type in slit 56
2022-12-02 15:57:20,419 - stpipe.WavecorrStep - INFO - Detected a EXTENDED source type in slit 57
2022-12-02 15:57:20,419 - stpipe.WavecorrStep - INFO - Detected a EXTENDED source type in slit 58
2022-12-02 15:57:20,419 - stpipe.WavecorrStep - INFO - Detected a EXTENDED source type in slit 59
2022-12-02 15:57:20,420 - stpipe.WavecorrStep - INFO - Detected a EXTENDED source type in slit 60
2022-12-02 15:57:20,420 - stpipe.WavecorrStep - INFO - Detected a EXTENDED source type in slit 61
2022-12-02 15:57:20,421 - stpipe.WavecorrStep - INFO - Detected a EXTENDED source type in slit 62
2022-12-02 15:57:20,421 - stpipe.WavecorrStep - INFO - Detected a EXTENDED source type in slit 63
2022-12-02 15:57:20,422 - stpipe.WavecorrStep - INFO - Detected a EXTENDED source type in slit 64
2022-12-02 15:57:20,422 - stpipe.WavecorrStep - INFO - Detected a EXTENDED source type in slit 67
2022-12-02 15:57:20,427 - stpipe.WavecorrStep - INFO - Results used CRDS context: jwst_1019.pmap
2022-12-02 15:57:20,427 - stpipe.WavecorrStep - INFO - Step WavecorrStep done
2022-12-02 15:57:20,481 - stpipe.FlatFieldStep - INFO - FlatFieldStep instance created.
2022-12-02 15:57:21,057 - stpipe.FlatFieldStep - INFO - Step FlatFieldStep running with args (<MultiSlitModel from mos_g140m_line1_NRS1_uncal.fits>,).
2022-12-02 15:57:21,060 - stpipe.FlatFieldStep - INFO - Step FlatFieldStep parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'save_interpolated_flat': False, 'user_supplied_flat': None, 'inverse': False}
2022-12-02 15:57:41,895 - stpipe.FlatFieldStep - INFO - Working on slit 53
2022-12-02 15:57:42,712 - stpipe.FlatFieldStep - INFO - Working on slit 54
2022-12-02 15:57:43,521 - stpipe.FlatFieldStep - INFO - Working on slit 42
2022-12-02 15:57:43,711 - stpipe.FlatFieldStep - INFO - Working on slit 43
2022-12-02 15:57:43,962 - stpipe.FlatFieldStep - INFO - Working on slit 44
2022-12-02 15:57:44,213 - stpipe.FlatFieldStep - INFO - Working on slit 45
2022-12-02 15:57:44,547 - stpipe.FlatFieldStep - INFO - Working on slit 46
2022-12-02 15:57:44,951 - stpipe.FlatFieldStep - INFO - Working on slit 47
2022-12-02 15:57:45,403 - stpipe.FlatFieldStep - INFO - Working on slit 48
2022-12-02 15:57:45,860 - stpipe.FlatFieldStep - INFO - Working on slit 49
2022-12-02 15:57:46,354 - stpipe.FlatFieldStep - INFO - Working on slit 50
2022-12-02 15:57:46,871 - stpipe.FlatFieldStep - INFO - Working on slit 51
2022-12-02 15:57:47,869 - stpipe.FlatFieldStep - INFO - Working on slit 52
2022-12-02 15:57:48,464 - stpipe.FlatFieldStep - INFO - Working on slit 55
2022-12-02 15:57:49,980 - stpipe.FlatFieldStep - INFO - Working on slit 65
2022-12-02 15:57:52,124 - stpipe.FlatFieldStep - INFO - Working on slit 66
2022-12-02 15:57:54,284 - stpipe.FlatFieldStep - INFO - Working on slit 68
2022-12-02 15:57:56,469 - stpipe.FlatFieldStep - INFO - Working on slit 56
2022-12-02 15:57:58,176 - stpipe.FlatFieldStep - INFO - Working on slit 57
2022-12-02 15:58:00,050 - stpipe.FlatFieldStep - INFO - Working on slit 58
2022-12-02 15:58:01,976 - stpipe.FlatFieldStep - INFO - Working on slit 59
2022-12-02 15:58:04,009 - stpipe.FlatFieldStep - INFO - Working on slit 60
2022-12-02 15:58:06,081 - stpipe.FlatFieldStep - INFO - Working on slit 61
2022-12-02 15:58:08,160 - stpipe.FlatFieldStep - INFO - Working on slit 62
2022-12-02 15:58:10,296 - stpipe.FlatFieldStep - INFO - Working on slit 63
2022-12-02 15:58:12,466 - stpipe.FlatFieldStep - INFO - Working on slit 64
2022-12-02 15:58:14,599 - stpipe.FlatFieldStep - INFO - Working on slit 67
2022-12-02 15:58:18,523 - stpipe.FlatFieldStep - INFO - Results used CRDS context: jwst_1019.pmap
2022-12-02 15:58:18,524 - stpipe.FlatFieldStep - INFO - Step FlatFieldStep done
2022-12-02 15:58:18,577 - stpipe.PathLossStep - INFO - PathLossStep instance created.
2022-12-02 15:58:19,240 - stpipe.PathLossStep - INFO - Step PathLossStep running with args (<MultiSlitModel from mos_g140m_line1_NRS1_uncal.fits>,).
2022-12-02 15:58:19,243 - stpipe.PathLossStep - INFO - Step PathLossStep parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'inverse': False, 'source_type': None}
2022-12-02 15:58:19,304 - stpipe.PathLossStep - INFO - Using PATHLOSS reference file /grp/crds/cache/references/jwst/jwst_nirspec_pathloss_0002.fits
2022-12-02 15:58:19,362 - stpipe.PathLossStep - INFO - Input exposure type is NRS_MSASPEC
2022-12-02 15:58:24,654 - stpipe.PathLossStep - INFO - Working on slit 0
2022-12-02 15:58:24,675 - stpipe.PathLossStep - INFO - Working on slit 1
2022-12-02 15:58:24,697 - stpipe.PathLossStep - INFO - Working on slit 2
2022-12-02 15:58:24,717 - stpipe.PathLossStep - INFO - Working on slit 3
2022-12-02 15:58:24,737 - stpipe.PathLossStep - INFO - Working on slit 4
2022-12-02 15:58:24,759 - stpipe.PathLossStep - INFO - Working on slit 5
2022-12-02 15:58:24,779 - stpipe.PathLossStep - INFO - Working on slit 6
2022-12-02 15:58:24,799 - stpipe.PathLossStep - INFO - Working on slit 7
2022-12-02 15:58:24,821 - stpipe.PathLossStep - INFO - Working on slit 8
2022-12-02 15:58:24,841 - stpipe.PathLossStep - INFO - Working on slit 9
2022-12-02 15:58:24,861 - stpipe.PathLossStep - INFO - Working on slit 10
2022-12-02 15:58:24,883 - stpipe.PathLossStep - INFO - Working on slit 11
2022-12-02 15:58:24,903 - stpipe.PathLossStep - INFO - Working on slit 12
2022-12-02 15:58:24,923 - stpipe.PathLossStep - INFO - Working on slit 13
2022-12-02 15:58:24,946 - stpipe.PathLossStep - INFO - Working on slit 14
2022-12-02 15:58:24,969 - stpipe.PathLossStep - INFO - Working on slit 15
2022-12-02 15:58:24,991 - stpipe.PathLossStep - INFO - Working on slit 16
2022-12-02 15:58:25,016 - stpipe.PathLossStep - INFO - Working on slit 17
2022-12-02 15:58:25,038 - stpipe.PathLossStep - INFO - Working on slit 18
2022-12-02 15:58:25,060 - stpipe.PathLossStep - INFO - Working on slit 19
2022-12-02 15:58:25,084 - stpipe.PathLossStep - INFO - Working on slit 20
2022-12-02 15:58:25,106 - stpipe.PathLossStep - INFO - Working on slit 21
2022-12-02 15:58:25,128 - stpipe.PathLossStep - INFO - Working on slit 22
2022-12-02 15:58:25,151 - stpipe.PathLossStep - INFO - Working on slit 23
2022-12-02 15:58:25,174 - stpipe.PathLossStep - INFO - Working on slit 24
2022-12-02 15:58:25,196 - stpipe.PathLossStep - INFO - Working on slit 25
2022-12-02 15:58:25,219 - stpipe.PathLossStep - INFO - Working on slit 26
2022-12-02 15:58:25,245 - stpipe.PathLossStep - INFO - Results used CRDS context: jwst_1019.pmap
2022-12-02 15:58:25,246 - stpipe.PathLossStep - INFO - Step PathLossStep done
2022-12-02 15:58:25,298 - stpipe.BarShadowStep - INFO - BarShadowStep instance created.
2022-12-02 15:58:25,794 - stpipe.BarShadowStep - INFO - Step BarShadowStep running with args (<MultiSlitModel from mos_g140m_line1_NRS1_uncal.fits>,).
2022-12-02 15:58:25,796 - stpipe.BarShadowStep - INFO - Step BarShadowStep parameters are: {'pre_hooks': [], 'post_hooks': [], 'output_file': None, 'output_dir': None, 'output_ext': '.fits', 'output_use_model': False, 'output_use_index': True, 'save_results': False, 'skip': False, 'suffix': None, 'search_output_file': True, 'input_dir': '', 'inverse': False, 'source_type': None}
2022-12-02 15:58:25,858 - stpipe.BarShadowStep - INFO - Using BARSHADOW reference file /grp/crds/cache/references/jwst/jwst_nirspec_barshadow_0001.fits
2022-12-02 15:58:31,409 - stpipe.BarShadowStep - INFO - Working on slitlet 53
2022-12-02 15:58:31,451 - stpipe.BarShadowStep - INFO - Working on slitlet 54
2022-12-02 15:58:31,492 - stpipe.BarShadowStep - INFO - Working on slitlet 42
2022-12-02 15:58:31,520 - stpipe.BarShadowStep - INFO - Working on slitlet 43
2022-12-02 15:58:31,547 - stpipe.BarShadowStep - INFO - Working on slitlet 44
2022-12-02 15:58:31,575 - stpipe.BarShadowStep - INFO - Working on slitlet 45
2022-12-02 15:58:31,607 - stpipe.BarShadowStep - INFO - Working on slitlet 46
2022-12-02 15:58:31,638 - stpipe.BarShadowStep - INFO - Working on slitlet 47
2022-12-02 15:58:31,671 - stpipe.BarShadowStep - INFO - Working on slitlet 48
2022-12-02 15:58:31,706 - stpipe.BarShadowStep - INFO - Working on slitlet 49
2022-12-02 15:58:31,740 - stpipe.BarShadowStep - INFO - Working on slitlet 50
2022-12-02 15:58:31,775 - stpipe.BarShadowStep - INFO - Working on slitlet 51
2022-12-02 15:58:31,812 - stpipe.BarShadowStep - INFO - Working on slitlet 52
2022-12-02 15:58:31,847 - stpipe.BarShadowStep - INFO - Working on slitlet 55
2022-12-02 15:58:31,908 - stpipe.BarShadowStep - INFO - Working on slitlet 65
2022-12-02 15:58:32,004 - stpipe.BarShadowStep - INFO - Working on slitlet 66
2022-12-02 15:58:32,147 - stpipe.BarShadowStep - INFO - Working on slitlet 68
2022-12-02 15:58:32,277 - stpipe.BarShadowStep - INFO - Working on slitlet 56
2022-12-02 15:58:32,347 - stpipe.BarShadowStep - INFO - Working on slitlet 57
2022-12-02 15:58:32,419 - stpipe.BarShadowStep - INFO - Working on slitlet 58
2022-12-02 15:58:32,495 - stpipe.BarShadowStep - INFO - Working on slitlet 59
2022-12-02 15:58:32,576 - stpipe.BarShadowStep - INFO - Working on slitlet 60
2022-12-02 15:58:32,659 - stpipe.BarShadowStep - INFO - Working on slitlet 61
2022-12-02 15:58:32,760 - stpipe.BarShadowStep - INFO - Working on slitlet 62
2022-12-02 15:58:32,864 - stpipe.BarShadowStep - INFO - Working on slitlet 63
2022-12-02 15:58:32,949 - stpipe.BarShadowStep - INFO - Working on slitlet 64
2022-12-02 15:58:33,035 - stpipe.BarShadowStep - INFO - Working on slitlet 67
2022-12-02 15:58:33,129 - stpipe.BarShadowStep - INFO - Results used CRDS context: jwst_1019.pmap
2022-12-02 15:58:33,130 - stpipe.BarShadowStep - INFO - Step BarShadowStep done
/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.9/site-packages/numpy/core/fromnumeric.py:3432: RuntimeWarning: Mean of empty slice.
  return _methods._mean(a, axis=axis, dtype=dtype,
/internal/data1/jenkins/workspace/Notebooks/jwst_validation_notebooks_spacetelescope/miniconda3/envs/jwst_validation_notebooks/lib/python3.9/site-packages/numpy/core/_methods.py:182: RuntimeWarning: invalid value encountered in divide
  ret = um.true_divide(


# Quickly see if the test passed 

print('These are the final results of the tests: ')
for key, val in results_dict.items():
    if not isinstance(val, str):
        if val:
            val = 'PASSED'
        else:
            val = 'FAILED'
    print('{:<42} {:<8}'.format(key, val))

These are the final results of the tests: 
mos_prism_nrs1_uncal.fits                  PASSED  
mos_prism_nrs2_uncal.fits                  skipped 
mos_g140m_line1_NRS1_uncal.fits            PASSED  
mos_g140m_line1_NRS2_uncal.fits            PASSED

JWST Pipeline Validation Testing Notebook: spec2, barshadow step¶

Table of Contents¶

Imports¶

Test Description¶

Results¶

Calibration WG Requested Algorithm:¶

Defining Term¶

Run the JWST pipeline and pathloss validation tests¶

Testing Data Set¶

About this Notebook¶